systemd bug: systemd-tmpfiles-setup.service fails with unknown user “systemd-network”

I had a strange error after updating “systemd” on one of my Opensuse server systems from version 228.41.1 to version 228.44.1. This update seems harmless, but it is not. With it substantial changes appear in the file /usr/lib/tmpfiles.d/systemd.conf. Especially the lines:

d /run/systemd/netif 0755 systemd-network systemd-network -
d /run/systemd/netif/links 0755 systemd-network systemd-network -
d /run/systemd/netif/leases 0755 systemd-network systemd-network -
</p>

In my case this lead to trouble – service “systemd-tmpfiles-setup.service” started to fail :

# systemctl status -l systemd-tmpfiles-setup
● systemd-tmpfiles-setup.service - Create Volatile Files and Directories
   Loaded: loaded (/lib/systemd/system/systemd-tmpfiles-setup.service; static)
   Active: failed (Result: exit-code) .....
...
...
Mar 12 11:33:32 myserv systemd-tmpfiles[509]: [/usr/lib/tmpfiles.d/systemd.conf:19] Unknown user 'systemd-network'.

I checked whether user “systemd-network” existed with YaST. Yes, it was there – with all its default details.
However the command

getent passwd systemd-network

did not give me anything!

It took me a bit to find out what had happened. On this server I had once experimented with NIS, NISplus. The “/etc/passwd”-file still contained a line

+::::::

The “/etc/group”-file had a corresponding “+:::”. However, no active NIS server is any longer defined. Should not matter as long as the file have a correct format, i.e. as long as the NIS-lines are placed at the bottom of the files …

But:
At some point in time (?) systemd had created the user “systemd-network” and a corresponding group. Unfortunately, both entries were dumbly added at the end of the files “/etc/passwd” and “/etc/group” – i.e. after the already existing NIS-lines.

systemd-timesync:x:478:478:systemd Time Synchronization:/:/sbin/nologin
+::::::
systemd-network:x:475:475:systemd Network Management:/:/sbin/nologin

Not funny! Because, this in turn became the cause for the empty “getent”-answer!

However, it seems that systemd now uses “getent” to check the existence of some special systemd-users like “systemd-network” as a requirement for starting certain services. Which then leads to errors …

Summary
“systemd” seems to add new user- and group-entries at the bottom of the files “/etc/passwd” and “/etc/group” – without checking for NIS lines. Or it at least did at some point in the past. This may prevent the start of some initial services for which the existence of user or group entries are checked.

So, if you run across a similar problem check your “passwd” and “group” files for wrong entries at the end of the file! Move the NIS lines to the very bottom of the files. Afterward “getent” will work again for all user entries – and your failed services hopefully will start again.

Note: If you still get errors for “unknown systemd-users” you have to check whether entries for all the required users really exist in “/etc/passwd”.

P.S.: The stupid thing on Opensuse is that YaST shows you the required users with passwd-entries below a NIS line as existing, whereas “getent” does not.

Linux-Namensgebung für physikalische Netzwerk-Devices

Opensuse nutzt ja seit längerem “systemd”. Zwei der größten Veränderungen, die damit einhergingen, war die intensive Nutzung von “udev” durch “systemd” im Rahmen des Systemstarts und eine resultierende Veränderung der Namensgebung für physikalische Devices – u.a. Netzwerkdevices. Alles unter dem Schlagwort “predictable device names”.

Einen großen Einfluss hatte das u.a. auf Netzwerk-Devices: An die Stelle der alten NIC-Bezeichnungen “eth0”, “eth1”, etc. traten dann auf meinem Desktop-System z.B. so illustre Ausdrücke wie “enp8s0”, “enp9s0” oder noch komplexere Namen.

Aus den netzwerk-bezogenen “udev”-Regeln in den Dateien unter “/lib/udev/rules.d” alleine konnte ich mir bislang nicht erklären, wie es zur Festlegung der Device-Namen kam. “Die “udev”-Regeln betreffen ja etliche unterschiedliche Identifikations-Bezeichnungen. Ich hatte die Namensvergabe daher bislang einfach als Ergebnis einer für mich nicht nachvollziehbaren “udev/systemd”-Logik abgetan.

In der Auseinandersetzung mit virtuellen Bridges bin ich jedoch wieder über das Thema und inzwischen auch über zwei Artikel gestolpert, die das Ganze erklären. Ich möchte an dieser Stelle gerne auf die betreffenden Artikel hinweisen:

Der erste lesenswerte Artikel stammt von Major Hayden, der der Sache mal nachgegangen ist:
https://major.io/2015/08/21/understanding-systemds-predictable-network-device-names/

Besonders hilfreich fand ich in dem zitierten Artikel den Auszug aus “src/udev/udev-builtin-net_id.c”, der einem hilft eine Zugang zu einer Namensvergabe wie “enp8s0” zu finden:

  
 * Two character prefixes based on the type of interface:
 *   en -- ethernet
 *   sl -- serial line IP (slip)
 *   wl -- wlan
 *   ww -- wwan
 *
 * Type of names:
 *   b<number>                             -- BCMA bus core number
 *   ccw<name>                             -- CCW bus group name
 *   o<index>[d<dev_port>]                 -- on-board device index number
 *   s<slot>[f<function>][d<dev_port>]     -- hotplug slot index number
 *   x<MAC>                                -- MAC address
 *   [P<domain>]p<bus>s<slot>[f<function>][d<dev_port>]
 *                                         -- PCI geographical location
 *   [P<domain>]p<bus>s<slot>[f<function>][u<port>][..][c<config>][i<interface>]
 *                                         -- USB port number chain

 
Der zweite Artikel betrifft die Regeln, nach denen “systemd” verschiedene Varianten der Namensgebung bis zu einer endgültigen Entscheidung für ein Netzwerk-Device durchexerziert:

http://www.freedesktop.org/wiki/Software/systemd/PredictableNetworkInterfaceNames/

Ich zitiere aus dem Artikel:

  
The following different naming schemes for network interfaces are now supported by udev natively:

    Names incorporating Firmware/BIOS provided index numbers for on-board devices (example: eno1)
    Names incorporating Firmware/BIOS provided PCI Express hotplug slot index numbers (example: ens1)
    Names incorporating physical/geographical location of the connector of the hardware (example: enp2s0)
    Names incorporating the interfaces's MAC address (example: enx78e7d1ea46da)
    Classic, unpredictable kernel-native ethX naming (example: eth0)

By default, systemd v197 will now name interfaces following policy 1) if that 
information from the firmware is applicable and available, falling back to 2) if that information from the firmware is applicable and available, falling back to 3) if applicable, falling back to 5) in all other cases. Policy 4) is not used by default, but is available if the user chooses so. 

 
Aha – das kann ich nachvollziehen.

Wer sich mit diesem Wissen ausgestattet auch mal ansehen will, was “udev” auf einem System alles an Definitionen für gefundene Netzwerk-Devices hinterlegt, nutze das Kommando

“udevadm info -e”

mit Filtern. Auf meinem Desktop-System etwa finde ich:

   
mytux:~ # udevadm info -e | grep net            
E: ID_MODEL_FROM_DATABASE=RTL8111/8168/8411 PCI Express Gigabit Ethernet Controller (Motherboard)
E: ID_PCI_SUBCLASS_FROM_DATABASE=Ethernet controller
P: /devices/pci0000:00/0000:00:1c.4/0000:08:00.0/net/enp8s0
E: DEVPATH=/devices/pci0000:00/0000:00:1c.4/0000:08:00.0/net/enp8s0
E: ID_MODEL_FROM_DATABASE=RTL8111/8168/8411 PCI Express Gigabit Ethernet Controller (Motherboard)
E: ID_NET_LINK_FILE=/usr/lib/systemd/network/99-default.link
E: ID_PCI_SUBCLASS_FROM_DATABASE=Ethernet controller
E: SUBSYSTEM=net
E: SYSTEMD_ALIAS=/sys/subsystem/net/devices/enp8s0 /sys/subsystem/net/devices/enp8s0

E: ID_MODEL_FROM_DATABASE=RTL8111/8168/8411 PCI Express Gigabit Ethernet Controller (Motherboard)
E: ID_PCI_SUBCLASS_FROM_DATABASE=Ethernet controller
P: /devices/pci0000:00/0000:00:1c.5/0000:09:00.0/net/enp9s0
E: DEVPATH=/devices/pci0000:00/0000:00:1c.5/0000:09:00.0/net/enp9s0
E: ID_MODEL_FROM_DATABASE=RTL8111/8168/8411 PCI Express Gigabit Ethernet Controller (Motherboard)
E: ID_NET_LINK_FILE=/usr/lib/systemd/network/99-default.link
E: ID_PCI_SUBCLASS_FROM_DATABASE=Ethernet controller
E: SUBSYSTEM=net
E: SYSTEMD_ALIAS=/sys/subsystem/net/devices/enp9s0 /sys/subsystem/net/devices/enp9s0

P: /devices/virtual/misc/network_latency
N: network_latency
E: DEVNAME=/dev/network_latency
E: DEVPATH=/devices/virtual/misc/network_latency
P: /devices/virtual/misc/network_throughput
N: network_throughput
E: DEVNAME=/dev/network_throughput
E: DEVPATH=/devices/virtual/misc/network_throughput
N: net/tun
E: DEVNAME=/dev/net/tun

P: /devices/virtual/net/br0
E: DEVPATH=/devices/virtual/net/br0
E: ID_NET_LINK_FILE=/usr/lib/systemd/network/99-default.link
E: SUBSYSTEM=net
E: SYSTEMD_ALIAS=/sys/subsystem/net/devices/br0

P: /devices/virtual/net/lo
E: DEVPATH=/devices/virtual/net/lo
E: ID_NET_LINK_FILE=/usr/lib/systemd/network/99-default.link
E: SUBSYSTEM=net

P: /devices/virtual/net/virbr0
E: DEVPATH=/devices/virtual/net/virbr0
E: ID_NET_LINK_FILE=/usr/lib/systemd/network/99-default.link
E: SUBSYSTEM=net
E: SYSTEMD_ALIAS=/sys/subsystem/net/devices/virbr0

P: /devices/virtual/net/virbr0-nic
E: DEVPATH=/devices/virtual/net/virbr0-nic
E: ID_NET_LINK_FILE=/usr/lib/systemd/network/99-default.link
E: SUBSYSTEM=net
E: SYSTEMD_ALIAS=/sys/subsystem/net/devices/virbr0-nic

P: /devices/virtual/net/virbr1
E: DEVPATH=/devices/virtual/net/virbr1
E: ID_NET_LINK_FILE=/usr/lib/systemd/network/99-default.link
E: SUBSYSTEM=net
E: SYSTEMD_ALIAS=/sys/subsystem/net/devices/virbr1

P: /devices/virtual/net/virbr1-nic
E: DEVPATH=/devices/virtual/net/virbr1-nic
E: ID_NET_LINK_FILE=/usr/lib/systemd/network/99-default.link
E: SUBSYSTEM=net
E: SYSTEMD_ALIAS=/sys/subsystem/net/devices/virbr1-nic

P: /devices/virtual/net/vmnet0
E: DEVPATH=/devices/virtual/net/vmnet0
E: ID_NET_LINK_FILE=/usr/lib/systemd/network/99-default.link
E: INTERFACE=vmnet0
E: SUBSYSTEM=net
E: SYSTEMD_ALIAS=/sys/subsystem/net/devices/vmnet0

P: /devices/virtual/net/vmnet1
E: DEVPATH=/devices/virtual/net/vmnet1
E: ID_NET_LINK_FILE=/usr/lib/systemd/network/99-default.link
nE: INTERFACE=vmnet1
E: SUBSYSTEM=net
E: SYSTEMD_ALIAS=/sys/subsystem/net/devices/vmnet1

P: /devices/virtual/net/vmnet2
E: DEVPATH=/devices/virtual/net/vmnet2
E: ID_NET_LINK_FILE=/usr/lib/systemd/network/99-default.link
E: INTERFACE=vmnet2
E: SUBSYSTEM=net
E: SYSTEMD_ALIAS=/sys/subsystem/net/devices/vmnet2

 
(Der erfahrene Leser erkennt, dass hier neben physikalischen Devices qemu-Bridges und auch VMware-Bridges aktiv sind. Für entsprechende Devices werden im Zusammenspiel mit den Generatoren der Virtualisierungs-Tools offenbar Standardnamen vergeben, da eindeutige Vendor- oder “geographische” Bus-Bezeichnungen nicht ermittelbar sind.)

Mein Dank gilt den Verfassern der oben genannten Artikel, die zumindest bei mir eine Verständnislücke geschlossen haben.

systemd Logging Protokolle – journalctl – Abfrage nach Services und Kommandos mit Autocompletion-Hilfe für Vergessliche

Als alter “syslog-ng” Nutzer tue ich mir immer wieder hart mit der Protokollierung durch “systemd”. Der Schlüssel-Befehl “journactl” ist mir natürlich präsent – aber welche Opionen muss ich dann wählen, um die Unzahl von Journal-Einträge nach solchen zu ganz bestimmten Services oder Kommandos zu filtern?

Den entscheidenden Tip für Dummies wie mich habe ich hier gefunden:
http://blog.delouw.ch/2013/07/24/why-journalctl-is-cool-and-syslog-will-survive-for-another-decade/
(Vielen Dank für den hilfreichen Blog-Artikel).

journactl hat eine Autocompletion-Funktionalität über die Tab-Taste:

Generelle Filter-Optionen erreicht man über

journalctl <TAB>[<TAB>]

Ggf. muss man die TAB-Taste 2-mal drücken.

mytux:~ # journalctl 
CODE_FILE=                   _KERNEL_DEVICE=
CODE_FUNC=                   _KERNEL_SUBSYSTEM=
CODE_LINE=                   _MACHINE_ID=
COREDUMP_EXE=                _PID=
ERRNO=                       _SELINUX_CONTEXT=
MESSAGE=                     _SOURCE_REALTIME_TIMESTAMP=
MESSAGE_ID=                  _SYSTEMD_CGROUP=
PRIORITY=                    _SYSTEMD_OWNER_UID=
SYSLOG_FACILITY=             _SYSTEMD_SESSION=
SYSLOG_IDENTIFIER=           _SYSTEMD_UNIT=
SYSLOG_PID=                  _TRANSPORT=
_AUDIT_LOGINUID=             _UDEV_DEVLINK=
_AUDIT_SESSION=              _UDEV_DEVNODE=
_BOOT_ID=                    _UDEV_SYSNAME=
_CMDLINE=                    _UID=
_COMM=                       __CURSOR=
_EXE=                        __MONOTONIC_TIMESTAMP=
_GID=                        __REALTIME_TIMESTAMP=
_HOSTNAME=                   

 
Das ist doch schon sehr hilfreich. Da die meisten System-Services direkt zu irgendwelchen “systemd UNITs” korrespondieren, kommt man hier schon ein gutes Stück weiter. Beispiel:

mytux:~ # journalctl _SYSTEMD_UNIT=sshd.service 
-- Logs begin at Fri 2014-12-19 17:40:02 CET, end at Sun 2015-09-27 19:02:35 CEST. --
......
-- Reboot --
Jan 24 10:49:37 mytux sshd-gen-keys-start[5942]: Checking for missing server keys in /etc/ssh
Jan 24 10:49:37 mytux sshd[5947]: Server listening on 0.0.0.0 port 22.
Jan 24 10:49:37 mytux sshd[5947]: Server listening on :: port 22.
Jan 24 10:50:03 mytux sshd[5971]: Accepted keyboard-interactive/pam for root from xxx.xxx.xxx.xxx port 33032 ssh2
Jan 24 10:50:03 mytux sshd[5971]: pam_unix(sshd:session): session opened for user root by (uid=0)
Jan 24 10:50:03 mytux sshd[6013]: Accepted keyboard-interactive/pam for root from xxx.xxx.xxx.xxx port 33033 ssh2
Jan 24 10:50:03 mytux sshd[6013]: pam_unix(sshd:session): session opened for user root by (uid=0)
Jan 24 12:10:20 mytux sshd[13201]: Accepted keyboard-interactive/pam for root from xxx.xxx.xxx.xxx port 33310 ssh2
.......

 
Oder:

mytux:~ # journalctl _SYSTEMD_UNIT=vmware.service 
-- Logs begin at Fri 2014-12-19 17:40:02 CET, end at Sun 2015-09-27 19:07:41 CEST. --
Jan 03 09:31:07 mytux vmware[1475]: Starting VMware services:
Jan 03 09:31:07 mytux vmware[1475]: [33B blob data]
Jan 03 09:31:07 mytux vmware[1475]: [49B blob data]
Jan 03 09:31:07 mytux vmware[1475]: [50B blob data]
Jan 03 09:31:07 mytux vmware[1475]: [30B blob data]
Jan 03 09:31:07 mytux vmnetBridge[1775]: Bridge process created.
Jan 03 09:31:07 mytux vmnetBridge[1775]: RTM_NEWLINK: name:enp8s0 index:2 flags:0x00011043
Jan 03 09:31:07 mytux vmnetBridge[1775]: Adding 
interface enp8s0 index:2
Jan 03 09:31:07 mytux vmnetBridge[1775]: Started bridge enp8s0 to virtual network 0.
.......

 
Erinnert man sich nicht mehr an laufende Services bzw. systemd-Units, so benutzt man die TAB-Taste erneut:

mytux:~ # journalctl  _SYSTEMD_UNIT=<TAB>[<TAB>]
Display all 196 possibilities? (y or n)

Das Ganze geht auch für Optionen:

journalctl  <TAB>[<TAB>]

Also:

mytux:~ # journalctl  -<TAB>[<TAB>]
--all             --system
--boot            --this-boot
--cursor          --unit
--directory       --until
--disk-usage      --update-catalog
--field           --user
--file            --user-unit
--follow          --verify
--full            --verify-key
--header          --version
--help            -D
--interval        -F
--lines           -a
--list-boots      -b
--list-catalog    -c
--local           -f
--merge           -h
--new-id128       -l
--no-pager        -m
--no-tail         -n
--output          -o
--priority        -p
--quiet           -q
--setup-keys      -u
--since           

 
Wie so oft führen bzgl. eines bestimmten Dienstes bzw. eines korrespondierenden Kommandos mehrere Wege zum Ziel:

mytux:~ # journalctl  _SYSTEMD_UNIT=sshd.service

oder

mytux:~ # journalctl  -u sshd

oder

mytux:~ # journalctl  –unit sshd

und

rux:~ # journalctl  _COMM=sshd

führen zu sehr ähnlichen Outputs. Der letzte Befehl zeigt am meisten an.

“_COMM” steht dabei für “Command” – das ermöglicht natürlich sehr vielfältige Filtermöglichkeiten – je nach Logging-Einstellungen.

Nun kombiniert man den Filter für eine Unit oder ein Komamndo noch mit einer Zeiteinschränkung über die Optionen “–since” und “–until” und jeweiligen Zeitstempeln im Format „2015-06-30 10:13:16“ – und schon fühlt man sich als Admin bzgl. der Analyse etwas besser. Z.B.:

mytux:~ # journalctl -u sshd –since “2015-06-30” –until “today”

Fazit: Durch die Autocompletion-Funktionalität wird einem der Gewöhnungsprozess an “journalctl” doch erheblich erleichtert. Man muss es halt nur wissen – und irgendwann sitzen die Kommando-Optionen auch bei mir.

Links:
https://wiki.archlinux.org/index.php/Systemd
http://0pointer.de/blog/projects/journalctl.html
https://access.redhat.com/documentation/en-US/Red_Hat_Enterprise_Linux/7/html/System_Administrators_Guide/s1-Using_the_Journal.html
https://www.digitalocean.com/community/tutorials/how-to-use-journalctl-to-view-and-manipulate-systemd-logs