Description of problem: Armhfp systems that use lvm fail to boot after upgrading to glibc-2.30.9000-17.fc32, waiting indefinitely: Version-Release number of selected component (if applicable): glibc-2.30.9000-17.fc32 lvm2-2.03.06-1.fc32.armv7hl systemd-udev-243-4.gitef67743.fc32.armv7hl How reproducible: Everytime Steps to Reproduce: 1. Boot disk image from Fedora-Rawhide-20191106.n.0 compose on armhfp device 2. upgrade glibc to glibc-2.30.9000-17.fc32+ 3. Use lvm commands Actual results: System hangs when booting with lvm, lvm commands fail Additional info: Using lvm commands manually on another system with glibc-2.30.9000-17.fc32+ # fdisk -l /dev/sdb Disk /dev/sdb: 7.47 GiB, 8004829184 bytes, 15634432 sectors Disk model: USB DISK 2.0 Units: sectors of 1 * 512 = 512 bytes Sector size (logical/physical): 512 bytes / 512 bytes I/O size (minimum/optimal): 512 bytes / 512 bytes Disklabel type: dos Disk identifier: 0x730bc46f Device Boot Start End Sectors Size Id Type /dev/sdb1 * 2048 2099199 2097152 1G 83 Linux /dev/sdb2 2099200 15634431 13535232 6.5G 8e Linux LVM [root@localhost ~]# lvs WARNING: Device /dev/sda not initialized in udev database even after waiting 10000000 microseconds. WARNING: Device /dev/mmcblk0 not initialized in udev database even after waiting 10000000 microseconds. WARNING: Device /dev/sda1 not initialized in udev database even after waiting 10000000 microseconds. WARNING: Device /dev/sda2 not initialized in udev database even after waiting 10000000 microseconds. WARNING: Device /dev/sda3 not initialized in udev database even after waiting 10000000 microseconds. WARNING: Device /dev/sda5 not initialized in udev database even after waiting 10000000 microseconds. WARNING: Device /dev/sdb not initialized in udev database even after waiting 10000000 microseconds. WARNING: Device /dev/sdb1 not initialized in udev database even after waiting 10000000 microseconds. WARNING: Device /dev/sdb2 not initialized in udev database even after waiting 10000000 microseconds. WARNING: Device /dev/mmcblk0 not initialized in udev database even after waiting 10000000 microseconds. WARNING: Device /dev/sda1 not initialized in udev database even after waiting 10000000 microseconds. WARNING: Device /dev/sda2 not initialized in udev database even after waiting 10000000 microseconds. WARNING: Device /dev/sda3 not initialized in udev database even after waiting 10000000 microseconds. systemctl status systemd-udevd ● systemd-udevd.service - udev Kernel Device Manager Loaded: loaded (/usr/lib/systemd/system/systemd-udevd.service; static; vendor preset: disabled) Active: active (running) since Thu 2019-10-10 08:56:18 EDT; 1 months 11 days ago Docs: man:systemd-udevd.service(8) man:udev(7) Main PID: 421 (systemd-udevd) Status: "Processing with 10 children at max" Tasks: 1 Memory: 14.8M CPU: 9.597s CGroup: /system.slice/systemd-udevd.service └─421 /usr/lib/systemd/systemd-udevd Oct 10 09:16:42 localhost.localdomain systemd-udevd[666]: sdb: Failed to process device, ignoring: Operation not permitted Oct 10 09:16:42 localhost.localdomain systemd-udevd[668]: sdb2: Failed to process device, ignoring: Operation not permitted Oct 10 09:16:42 localhost.localdomain systemd-udevd[666]: sdb1: Failed to process device, ignoring: Operation not permitted Oct 10 09:16:42 localhost.localdomain systemd-udevd[421]: Failed to touch /run/udev/queue: Operation not permitted Oct 10 09:16:42 localhost.localdomain systemd-udevd[668]: dm-0: Failed to process device, ignoring: Operation not permitted Oct 10 09:16:42 localhost.localdomain systemd-udevd[669]: dm-1: Failed to process device, ignoring: Operation not permitted Oct 10 09:16:43 localhost.localdomain systemd-udevd[668]: dm-0: Failed to process device, ignoring: Operation not permitted Oct 10 09:16:43 localhost.localdomain systemd-udevd[666]: dm-1: Failed to process device, ignoring: Operation not permitted Oct 10 09:16:52 localhost.localdomain systemd-udevd[421]: Failed to touch /run/udev/queue: Operation not permitted Oct 10 09:16:52 localhost.localdomain systemd-udevd[687]: card0: Failed to process device, ignoring: Operation not permitted
Is this real hardware, or QEMU? If the latter, which kind? Is there anything in the audit log?
On the real hardware (Raspberry Pi 3 and Banana Pi). Not seeing anything in audit.log: cat /var/log/audit/audit.log | grep lvm2 type=SERVICE_START msg=audit(1574307737.071:121): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=lvm2-monitor comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'UID="root" AUID="unset" type=SERVICE_START msg=audit(1574309167.423:136): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=lvm2-pvscan@8:34 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'UID="root" AUID="unset" type=SERVICE_START msg=audit(1574309208.745:145): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=lvm2-pvscan@8:18 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'UID="root" AUID="unset" type=SERVICE_START msg=audit(1574309386.982:121): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=lvm2-pvscan@8:18 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'UID="root" AUID="unset" type=SERVICE_STOP msg=audit(1574309388.820:133): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=lvm2-pvscan@8:18 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'UID="root" AUID="unset" type=SERVICE_START msg=audit(1574309673.247:122): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=lvm2-pvscan@8:18 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'UID="root" AUID="unset" type=SERVICE_STOP msg=audit(1574309977.200:205): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=lvm2-pvscan@8:18 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'UID="root" AUID="unset" [root@rpi3-5 ~]# cat /var/log/audit/audit.log | grep udev type=SERVICE_START msg=audit(1570712185.621:61): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=systemd-udevd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'UID="root" AUID="unset"
Created attachment 1638488 [details] lvs verbose output
Comment on attachment 1638488 [details] lvs verbose output Has the command been executed correctly? 09:23:44.236905 lvs[692] cache/lvmcache.c:276 lvmcache has no info for vgname "lvs.txt". Why lvs.txt?
Created attachment 1638499 [details] lvs verbose output Fixed, sorry about that.
Thanks. I would have expected denied system calls in the audit. In the log output, the time stamps align with the waiting, so that is good. I was worried that we broke something in the time-related system call wrappers, considering all the Y2038 work that is currently happening. Sorry, I do not have a way to debug this further.
Created attachment 1638552 [details] Fedora-Rawhide-20191108.n.0 boot log This also affects installations when glibc-2.30.9000-17.fc32 was added, booting with "debug systemd.log_level=debug udev.log_priority=debug rd.udev.log_priority=debug" doesn't seem to give any useful output and ends with (full logs attached): [ 90.046073] systemd-udevd (784) used greatest stack depth: 4992 bytes left [ 90.132279] systemd-udevd (783) used greatest stack depth: 4972 bytes left [ 90.141240] systemd-udevd (782) used greatest stack depth: 4644 bytes left [ OK ] Started Create Volatile Files and Directories.[ 90.728507] audit: type=1130 audit(1570712207.728:11): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=systemd-tmpfiles-setup comm="systemd" exe="/usr/lib/systemd' [ OK ] Reached target System Initialization. [ OK ] Listening on Open-iSCSI iscsid Socket. [ OK ] Listening on Open-iSCSI iscsiuio Socket. [ OK ] Reached target Sockets. [ OK ] Reached target Basic System. Starting iSCSI UserSpace I/O driver... [ 90.862804] systemd-journald[288]: Successfully sent stream file descriptor to service manager. [ OK ] Started iSCSI UserSpace I/O driver.[ 90.951496] audit: type=1130 audit(1570712207.951:12): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=iscsiuio comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr' Starting Open-iSCSI... [ OK ] Started Open-iSCSI. [ 91.360853] audit: type=1130 audit(1570712208.360:13): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=kernel msg='unit=iscsid comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success' [ 169.942795] systemd-journald[288]: Sent WATCHDOG=1 notification. [ 229.941127] systemd-journald[288]: Sent WATCHDOG=1 notification. [ 339.940934] systemd-journald[288]: Sent WATCHDOG=1 notification. [ 409.942431] systemd-journald[288]: Sent WATCHDOG=1 notification.
Does downgrading to 2.30.9000-16 fix the issue? That would at least allow us to track down which *week* the change occurred on and what impact it had (we sync Rawhide weekly).
Yes, glibc-2.30.9000-16.fc32 works as expected. Downgrading allows lvm commands to work.
To simplify bisection, I have started a scratch build with broken-out patches: https://koji.fedoraproject.org/koji/taskinfo?taskID=39202209 (Some patches for Hurd and locale-only chanhes I dropped, so it's best to verify the .38 build first.) SRPM is also available here: https://people.redhat.com/~fweimer/glibc-2.30.9000-16.bz1775157.38.fc32.src.rpm
Paul, Do you know if anyone else is running into this? We're trying to determine if this is some kind of common-mode failure across the systems you are using e.g. corrupted NFS disk etc.
This is working again in 'Fedora-Rawhide-20191122.n.0' and onward. The version of glibc did not change (glibc-2.30.9000-19.fc32). Last broken compose was Fedora-Rawhide-20191119.n.2. Limiting updates this appears to be fixed by libseccomp-2.4.2-1.fc32.armv7hl . Once installed lvm commands work as expected. I also confirmed once libseccomp-2.4.2-1.fc32 was included in Rawhide installs worked as expected. Apologies for the noise (and thanks for your help).
Thanks for the feedback!