Systemd-Logind: Fail to connect to DBus

[chemafv27]

Hi,

After upgrading dirtypipe from pve-no-subscription.

:~# pveversion  --verbose
proxmox-ve: 7.1-1 (running kernel: 5.13.19-5-pve)
pve-manager: 7.1-10 (running version: 7.1-10/6ddebafe)
pve-kernel-helper: 7.1-12
pve-kernel-5.13: 7.1-8
pve-kernel-5.11: 7.0-10
pve-kernel-5.13.19-5-pve: 5.13.19-13
pve-kernel-5.13.19-4-pve: 5.13.19-9
pve-kernel-5.13.19-3-pve: 5.13.19-7
pve-kernel-5.13.19-2-pve: 5.13.19-4
pve-kernel-5.11.22-7-pve: 5.11.22-12
ceph-fuse: 14.2.21-1
corosync: 3.1.5-pve2
criu: 3.15-1+pve-1
glusterfs-client: 9.2-1
ifupdown: residual config
ifupdown2: 3.1.0-1+pmx3
ksm-control-daemon: 1.4-1
libjs-extjs: 7.0.0-1
libknet1: 1.22-pve2
libproxmox-acme-perl: 1.4.1
libproxmox-backup-qemu0: 1.2.0-1
libpve-access-control: 7.1-6
libpve-apiclient-perl: 3.2-1
libpve-common-perl: 7.1-3
libpve-guest-common-perl: 4.1-1
libpve-http-server-perl: 4.1-1
libpve-storage-perl: 7.1-1
libqb0: 1.0.5-1
libspice-server1: 0.14.3-2.1
lvm2: 2.03.11-2.1
lxc-pve: 4.0.11-1
lxcfs: 4.0.11-pve1
novnc-pve: 1.3.0-2
openvswitch-switch: 2.15.0+ds1-2
proxmox-backup-client: 2.1.5-1
proxmox-backup-file-restore: 2.1.5-1
proxmox-mini-journalreader: 1.3-1
proxmox-widget-toolkit: 3.4-6
pve-cluster: 7.1-3
pve-container: 4.1-4
pve-docs: 7.1-2
pve-edk2-firmware: 3.20210831-2
pve-firewall: 4.2-5
pve-firmware: 3.3-5
pve-ha-manager: 3.3-3
pve-i18n: 2.6-2
pve-qemu-kvm: 6.1.1-2
pve-xtermjs: 4.16.0-1
qemu-server: 7.1-4
smartmontools: 7.2-pve2
spiceterm: 3.2-2
swtpm: 0.7.0~rc1+2
vncterm: 1.7-1
zfsutils-linux: 2.1.2-pve1

First of all, systemd-timesynd produced a boot loop and the machine was unable to boot completely unless reboot into systemd.unit=emergency.target and:

systemctl mask systemd-timesyncd

After that I installed Chrony.
There are issues but at least, it boots.
Chrony was unable to boot due to systemd Protect directives:

:~# cat /etc/systemd/system/chrony.service.d/override.conf
[Service]
PrivateTmp=no
ProtectHome=no
ProtectSystem=no
ProtectControlGroups=no
ProtectKernelModules=no
ProtectKernelTunables=no

If I enable any of them and the result is EXEC/203 on systemct status chrony. I would like the service to be protected as well as others but obviously these were the source of the problem.

After that machine machine boots but there is a problem. I guess there is something relative to namespaces but I dont know exactly what is happening.

Starting a container reports this issue:

~# pct start 117
lxc_spawn: 1728 Operation not permitted - Failed to clone a new set of namespaces
__lxc_start: 2068 Failed to spawn container "117"
startup for container '117' failed

systemd-logind
seems unable to load. Fails repeatedly, so I take syslog output:

Mar  9 08:16:17 ve0 systemd-logind[81208]: Failed to connect to system bus: No such file or directory
Mar  9 08:16:17 ve0 systemd-logind[81208]: Failed to fully start up daemon: No such file or directory

I think it was Dbus socket but everything seems to be fine:

root@ve0:~# systemctl status dbus.service dbus.socket
● dbus.service - D-Bus System Message Bus
     Loaded: loaded (/lib/systemd/system/dbus.service; static)
     Active: active (running) since Wed 2022-03-09 07:56:27 CET; 21min ago
TriggeredBy: ● dbus.socket
       Docs: man:dbus-daemon(1)
   Main PID: 1868 (dbus-daemon)
      Tasks: 1 (limit: 314572)
     Memory: 1.3M
        CPU: 11ms
     CGroup: /system.slice/dbus.service
             └─1868 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation --syslog-only

Mar 09 07:56:27 ve0 systemd[1]: Started D-Bus System Message Bus.
Mar 09 07:56:27 ve0 dbus-daemon[1868]: [system] AppArmor D-Bus mediation is enabled

● dbus.socket - D-Bus System Message Bus Socket
     Loaded: loaded (/lib/systemd/system/dbus.socket; static)
     Active: active (running) since Wed 2022-03-09 07:56:27 CET; 21min ago
   Triggers: ● dbus.service
     Listen: /run/dbus/system_bus_socket (Stream)
      Tasks: 0 (limit: 314572)
     Memory: 0B
        CPU: 0
     CGroup: /system.slice/dbus.socket

Mar 09 07:56:27 ve0 systemd[1]: Listening on D-Bus System Message Bus Socket.
root@ve0:~#

I've looked on previous posts and I've found that maybe /var/run symlink was broken but no, it looks fine:

root@ve0:~# ls -la /var/run
lrwxrwxrwx 1 root root 4 Jul 15  2019 /var/run -> /run

So, at this point I don't know exactly how to continue troubleshooting this.

Thanks in advance.

Greetings,
Chema.

 

[chemafv27]

I'll add some information here:

I've tried both kernels 5.15 & 5.13 same bootconfig. The results are the same.

Kernel Cmdline

initrd=\EFI\proxmox\5.15.19-2-pve\initrd.img-5.15.19-2-pve root=ZFS=rpool/ROOT/pve-1 boot=zfs intel_iommu=on acpi=on iommu.strict=0  mitigations=off elevator=deadline  intel_iommu=on iommu=pt pcie_acs_override=downstream pci_pt_e820_access=on pci=assign-busses pci=reall

Protect errors on Systemd-Login:
Commented lines produce errors:

### /etc/systemd/system/systemd-logind (temp)
[Service]
BusName=org.freedesktop.login1
CapabilityBoundingSet=CAP_SYS_ADMIN CAP_MAC_ADMIN CAP_AUDIT_CONTROL CAP_CHOWN CAP_DAC_READ_SEARCH CAP_DAC_OVERRIDE CAP_FOWNER CAP_SYS_TTY_CONFIG CAP_LINUX_IMMUTABLE
DeviceAllow=block-* r
DeviceAllow=char-/dev/console rw
DeviceAllow=char-drm rw
DeviceAllow=char-input rw
DeviceAllow=char-tty rw
DeviceAllow=char-vcs rw
ExecStart=/lib/systemd/systemd-logind
#FileDescriptorStoreMax=512
IPAddressDeny=any
LockPersonality=yes
MemoryDenyWriteExecute=yes
NoNewPrivileges=yes
#PrivateTmp=yes
#ProtectProc=invisible
ProtectClock=yes
#ProtectControlGroups=yes
#ProtectHome=yes
ProtectHostname=yes
#ProtectKernelLogs=yes
#ProtectKernelModules=yes
#ProtectSystem=yes
#ReadWritePaths=/etc /run
Restart=no
RestartSec=0
RestrictAddressFamilies=AF_UNIX AF_NETLINK
RestrictNamespaces=yes
RestrictRealtime=yes
RestrictSUIDSGID=yes
RuntimeDirectory=systemd/sessions systemd/seats systemd/users systemd/inhibit systemd/shutdown
RuntimeDirectoryPreserve=no
StateDirectory=systemd/linger
SystemCallArchitectures=native
SystemCallErrorNumber=EPERM
SystemCallFilter=@system-service
WatchdogSec=3min

# Increase the default a bit in order to allow many simultaneous logins since
# we keep one fd open per session.
LimitNOFILE=524288

Most of errors produced when enabling them look like this one:

Mar  9 08:44:18 ve0 systemd[77680]: systemd-logind.service: Failed to set up mount namespacing: /run/systemd/unit-root/proc/sys/kernel/domainname: No such file or directory
Mar  9 08:44:18 ve0 systemd[77680]: systemd-logind.service: Failed at step NAMESPACE spawning /lib/systemd/systemd-logind: No such file or directory
Mar  9 08:44:18 ve0 systemd[1]: systemd-logind.service: Main process exited, code=exited, status=226/NAMESPACE

Hope it helps a bit.

Greetings,
Chema.

 

[chemafv27]

I've been checking configs on the other cluster member.

As outlined on: https://forum.proxmox.com/threads/dirtypipe-cve-2022-0847-fix-for-proxmox-ve.106096/#post-456739 everything worked fine on this one. Errors arised when I've upgraded this node.

As far as there are notable diffs between configs and hardware, on both cluster nodes, I do not think the upgrade or kernel version is involved at all. Therefore, I opened this separated thread.

Maybe I've maid a mistake.

For now, the last step to start LXCs seems to be related to lxcfs. The service does not start. The reason for that, seems to be this:

root@ve0:~# strace /usr/bin/lxcfs  /var/lib/lxcfs 
....
openat(AT_FDCWD, "/var/lib/lxcfs", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 19
fstat(19, {st_mode=S_IFDIR|0755, st_size=2, ...}) = 0
getdents64(19, 0x56224271b3c0 /* 2 entries */, 32768) = 48
getdents64(19, 0x56224271b3c0 /* 0 entries */, 32768) = 0
close(19)                               = 0
openat(AT_FDCWD, "/dev/fuse", O_RDWR)   = -1 ENOENT (No such file or directory)
write(2, "fuse: device not found, try 'mod"..., 50fuse: device not found, try 'modprobe fuse' first
) = 50
write(2, "Running destructor lxcfs_exit\n", 30Running destructor lxcfs_exit
) = 30
...
+++ exited with 1 +++

But /dev/fuse exists.

root@ve0:~# ls -la /dev/fuse
crw-rw-rw- 1 root root 10, 229 Mar  9 11:45 /dev/fuse

Any ideas of what's happening ?

Greetings,
Chema

 

[chemafv27]

Good morning,

I've located the problem. It has nothing to do with any bug or upgrade related errors.

The issue, was that the mountpoint of some backups done via ZFS send/recv pointed to /.

root@ve0:~# zfs get mountpoint | grep -P 'pve-1 '
Backups/rpool_dirty/ROOT/pve-1                                             mountpoint  /                                         local
bpool/meci/ROOT/pve-1                                                      mountpoint  /                                         local
rpool/ROOT/pve-1                                                           mountpoint  /                                            received

Therefore, after mounting rpool/ROOT/pve-1 they overlayed mountpoint / with another backup.
As far as I understand, not all of Systemd's targets and units depend on zfs.target so it was launched in the middle of the boot so these filesystems where mounted over rpool/ROOT/pve-1 and produced all these extrange behaviors on protections.

Some Systemd units started over the correct ZFS and some of them not. I dont think it would have a deterministic behavior at all...

Fix:

root@ve0:~# zfs set mountpoint=none Backups/rpool_dirty/ROOT/pve-1
root@ve0:~# zfs set mountpoint=none bpool/meci/ROOT/pve-1
root@ve0:~# zfs get mountpoint | grep -P 'pve-1 '
Backups/rpool_dirty/ROOT/pve-1                                             mountpoint  none                                         local
bpool/meci/ROOT/pve-1                                                      mountpoint  none                                         local
rpool/ROOT/pve-1                                                           mountpoint  /                                            received
root@ve0:~# reboot

For sure there would be other solutions. For example, canmount=off.

I hope it helps. Next time, for sure, I'll remember to overwrite these ZFS properties after you receive them.

Greetings,
Chema.

 

[Helmut101]

Wow, this hit me hard, too. Had this on my offsite ZFS backup, where I received ZFS datasets/snapshots with Syncoid. This was really tricky to identify, thank you for reporting!