Bug 2088658 - [Fedora-Rawhide] WARNING: Device /dev/xx not initialized in udev database even after waiting 10000000 microseconds.
Summary: [Fedora-Rawhide] WARNING: Device /dev/xx not initialized in udev database eve...
Keywords:
Status: NEW
Alias: None
Product: Fedora
Classification: Fedora
Component: lvm2
Version: 37
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: LVM Team
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2022-05-20 01:27 UTC by guazhang@redhat.com
Modified: 2023-08-02 02:20 UTC (History)
14 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed:
Type: Bug
Embargoed:


Attachments (Terms of Use)
sosreport-kvm-04-guest03-2022-05-19-foppyfh.tar.xz (12.12 MB, application/x-tar)
2022-05-20 01:33 UTC, guazhang@redhat.com
no flags Details

Description guazhang@redhat.com 2022-05-20 01:27:25 UTC
Description of problem:
CKI storage regression testing failed and found the waring ' WARNING: Device /dev/ram1 not initialized in udev database even after waiting 10000000 microseconds.' in log, and the case will timeout. 
 

Version-Release number of selected component (if applicable):
lvm2-libs-2.03.11-7.fc36.x86_64
lvm2-2.03.11-7.fc36.x86_64
systemd-libs-251~rc3-1.fc37.x86_64
systemd-networkd-251~rc3-1.fc37.x86_64
systemd-pam-251~rc3-1.fc37.x86_64
systemd-resolved-251~rc3-1.fc37.x86_64
systemd-251~rc3-1.fc37.x86_64
systemd-udev-251~rc3-1.fc37.x86_64
rpm-plugin-systemd-inhibit-4.18.0-0.alpha1.6.fc37.x86_64
systemd-oomd-defaults-251~rc3-1.fc37.noarch
systemd-rpm-macros-251~rc3-1.fc37.noarch
[root@kvm-04-guest03 common]# uname -a
Linux kvm-04-guest03.hv2.lab.eng.bos.redhat.com 5.15.40-rt43 #1 SMP Mon May 16 19:25:09 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
[root@kvm-04-guest03 common]# 
[root@kvm-04-guest03 common]# rpm -qa |grep udev
systemd-udev-251~rc3-1.fc37.x86_64
libgudev-237-2.fc36.x86_64
python3-pyudev-0.23.2-1.fc37.noarch


How reproducible:
Several times

Steps to Reproduce:
1. create a loop device 
2. create some partition on loop
3. create lvm with the loop partition
4. mount the lvm and run dd 
5. remove lvm
6. remove loop


fallocate -l 4096M /var/tmp/loop1.img
losetup /dev/loop1 /var/tmp/loop1.img
parted -s /dev/loop1 mklabel MSDOS
parted -s /dev/loop1 mkpart pri 1 1248
parted -s /dev/loop1 mkpart ext 1249 3814
parted -s /dev/loop1 mkpart log 1249 1728
parted -s /dev/loop1 mkpart log 1729 1760
parted -s /dev/loop1 mkpart log 1761 2016
parted -s /dev/loop1 mkpart log 2017 2047
parted -s /dev/loop1 mkpart log 2048 2687
parted -s /dev/loop1 mkpart log 2688 3007
parted -s /dev/loop1 mkpart log 3008 3320
parted -s /dev/loop1 mkpart log 3321 3336
parted -s /dev/loop1 mkpart log 3337 3814
vgcreate  vgtest /dev/loop1p1 /dev/loop1p5 /dev/loop1p8 /dev/loop1p9 /dev/loop1p10 /dev/loop1p11 /dev/loop1p13
lvcreate -l 100%FREE -y vgtest -n testvol
mkfs.xfs /dev/mapper/vgtest-testvol
mount /dev/mapper/vgtest-testvol /tmp/test_mount
dd if=/dev/urandom of=/tmp/test_mount/test_file bs=3K count=1128966 status=progress
umount /tmp/test_mount
vgremove --force vgtest
pvremove  /dev/loop1p1
....








==============================================================================================================
Running test 'dm/block_boundary_obedience'
==============================================================================================================
INFO: [2022-05-19 10:36:05] Running: 'fmf_tier='1' fmf_expected_fstrim_out='' fmf_expected_fstrim_ret='0' fmf_name='dm/block_boundary_obedience' python3 /usr/local/lib/python3.10/site-packages/stqe/tests/dm/block_boundary_obedience.py'...

INFO: [2022-05-19 10:36:05] the device is loop1 with params cmd = lsblk | grep loop1
INFO: [2022-05-19 10:36:05] Running: 'lsblk | grep loop1'...
loop1                              7:1    0    4G  0 loop

INFO: [2022-05-19 10:36:05] Running parted cmd 'parted -s /dev/loop1 mklabel MSDOS' with params cmd = parted -s /dev/loop1 mklabel MSDOS
INFO: [2022-05-19 10:36:05] Running: 'parted -s /dev/loop1 mklabel MSDOS'...


INFO: [2022-05-19 10:36:05] Running parted cmd 'parted -s /dev/loop1 mkpart pri 1 1248' with params cmd = parted -s /dev/loop1 mkpart pri 1 1248
INFO: [2022-05-19 10:36:05] Running: 'parted -s /dev/loop1 mkpart pri 1 1248'...


INFO: [2022-05-19 10:36:05] Running parted cmd 'parted -s /dev/loop1 mkpart ext 1249 3814' with params cmd = parted -s /dev/loop1 mkpart ext 1249 3814
INFO: [2022-05-19 10:36:05] Running: 'parted -s /dev/loop1 mkpart ext 1249 3814'...


INFO: [2022-05-19 10:36:05] Running parted cmd 'parted -s /dev/loop1 mkpart log 1249 1728' with params cmd = parted -s /dev/loop1 mkpart log 1249 1728
INFO: [2022-05-19 10:36:05] Running: 'parted -s /dev/loop1 mkpart log 1249 1728'...
Warning: The resulting partition is not properly aligned for best performance: 2439170s % 2048s != 0s

INFO: [2022-05-19 10:36:05] Running parted cmd 'parted -s /dev/loop1 mkpart log 1729 1760' with params cmd = parted -s /dev/loop1 mkpart log 1729 1760
INFO: [2022-05-19 10:36:05] Running: 'parted -s /dev/loop1 mkpart log 1729 1760'...


INFO: [2022-05-19 10:36:05] Running parted cmd 'parted -s /dev/loop1 mkpart log 1761 2016' with params cmd = parted -s /dev/loop1 mkpart log 1761 2016
INFO: [2022-05-19 10:36:05] Running: 'parted -s /dev/loop1 mkpart log 1761 2016'...


INFO: [2022-05-19 10:36:05] Running parted cmd 'parted -s /dev/loop1 mkpart log 2017 2047' with params cmd = parted -s /dev/loop1 mkpart log 2017 2047
INFO: [2022-05-19 10:36:05] Running: 'parted -s /dev/loop1 mkpart log 2017 2047'...


INFO: [2022-05-19 10:36:06] Running parted cmd 'parted -s /dev/loop1 mkpart log 2048 2687' with params cmd = parted -s /dev/loop1 mkpart log 2048 2687
INFO: [2022-05-19 10:36:06] Running: 'parted -s /dev/loop1 mkpart log 2048 2687'...
Warning: The resulting partition is not properly aligned for best performance: 4000000s % 2048s != 0s

INFO: [2022-05-19 10:36:06] Running parted cmd 'parted -s /dev/loop1 mkpart log 2688 3007' with params cmd = parted -s /dev/loop1 mkpart log 2688 3007
INFO: [2022-05-19 10:36:06] Running: 'parted -s /dev/loop1 mkpart log 2688 3007'...


INFO: [2022-05-19 10:36:06] Running parted cmd 'parted -s /dev/loop1 mkpart log 3008 3320' with params cmd = parted -s /dev/loop1 mkpart log 3008 3320
INFO: [2022-05-19 10:36:06] Running: 'parted -s /dev/loop1 mkpart log 3008 3320'...


INFO: [2022-05-19 10:36:06] Running parted cmd 'parted -s /dev/loop1 mkpart log 3321 3336' with params cmd = parted -s /dev/loop1 mkpart log 3321 3336
INFO: [2022-05-19 10:36:06] Running: 'parted -s /dev/loop1 mkpart log 3321 3336'...


INFO: [2022-05-19 10:36:06] Running parted cmd 'parted -s /dev/loop1 mkpart log 3337 3814' with params cmd = parted -s /dev/loop1 mkpart log 3337 3814
INFO: [2022-05-19 10:36:06] Running: 'parted -s /dev/loop1 mkpart log 3337 3814'...


INFO: [2022-05-19 10:36:06] Creating VG 'vgtest' with params vg_name = vgtest, pv_name = /dev/loop1p1 /dev/loop1p5 /dev/loop1p8 /dev/loop1p9 /dev/loop1p10 /dev/loop1p11 /dev/loop1p13
INFO: [2022-05-19 10:36:06] Running: 'vgcreate  vgtest /dev/loop1p1 /dev/loop1p5 /dev/loop1p8 /dev/loop1p9 /dev/loop1p10 /dev/loop1p11 /dev/loop1p13'...
  Physical volume "/dev/loop1p1" successfully created.
  Physical volume "/dev/loop1p5" successfully created.
  Physical volume "/dev/loop1p8" successfully created.
  Physical volume "/dev/loop1p9" successfully created.
  Physical volume "/dev/loop1p10" successfully created.
  Physical volume "/dev/loop1p11" successfully created.
  Physical volume "/dev/loop1p13" successfully created.
  Volume group "vgtest" successfully created
  WARNING: Device /dev/ram0 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram1 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram2 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram3 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram4 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram5 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram6 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram7 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram8 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram9 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram10 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram11 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram12 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram13 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram14 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram15 not initialized in udev database even after waiting 10000000 microseconds.

INFO: [2022-05-19 10:38:47] Creating LV with params lv_name = testvol, vg_name = vgtest, options = ['-l 100%FREE', '-y']
INFO: [2022-05-19 10:38:47] Running: 'lvcreate -l 100%FREE -y vgtest -n testvol'...
  Logical volume "testvol" created.
  WARNING: Device /dev/ram0 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram1 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram2 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram3 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram4 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram5 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram6 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram7 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram8 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram9 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram10 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram11 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram12 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram13 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram14 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram15 not initialized in udev database even after waiting 10000000 microseconds.

INFO: [2022-05-19 10:41:27] Creating filesystem with params device_name = /dev/mapper/vgtest-testvol, fs_type = xfs
INFO: [2022-05-19 10:41:27] Running: 'mkfs.xfs /dev/mapper/vgtest-testvol'...
meta-data=/dev/mapper/vgtest-testvol isize=512    agcount=4, agsize=212736 blks
         =                       sectsz=512   attr=2, projid32bit=1
         =                       crc=1        finobt=1, sparse=1, rmapbt=0
         =                       reflink=1    bigtime=1 inobtcount=1
data     =                       bsize=4096   blocks=850944, imaxpct=25
         =                       sunit=0      swidth=0 blks
naming   =version 2              bsize=4096   ascii-ci=0, ftype=1
log      =internal log           bsize=4096   blocks=16384, version=2
         =                       sectsz=512   sunit=0 blks, lazy-count=1
realtime =none                   extsz=4096   blocks=0, rtextents=0
Discarding blocks...Done.

INFO: [2022-05-19 10:41:27] Creating mount dir with params new_dir = /tmp/test_mount

INFO: [2022-05-19 10:41:27] Mounting to /tmp/test_mount with params device = /dev/mapper/vgtest-testvol, mountpoint = /tmp/test_mount
INFO: [2022-05-19 10:41:27] Running: 'mount /dev/mapper/vgtest-testvol /tmp/test_mount'...


INFO: [2022-05-19 10:41:27] Creating test file with params cmd = dd if=/dev/urandom of=/tmp/test_mount/test_file bs=3K count=1128966 status=progress
INFO: [2022-05-19 10:41:27] Running: 'dd if=/dev/urandom of=/tmp/test_mount/test_file bs=3K count=1128966 status=progress'...

146651136 bytes (147 MB, 140 MiB) copied, 1 s, 147 MB/s
297796608 bytes (298 MB, 284 MiB) copied, 2 s, 149 MB/s
424919040 bytes (425 MB, 405 MiB) copied, 3 s, 142 MB/s
555475968 bytes (555 MB, 530 MiB) copied, 4 s, 139 MB/s
690091008 bytes (690 MB, 658 MiB) copied, 5 s, 138 MB/s
796563456 bytes (797 MB, 760 MiB) copied, 6 s, 133 MB/s
917686272 bytes (918 MB, 875 MiB) copied, 7 s, 131 MB/s
1042323456 bytes (1.0 GB, 994 MiB) copied, 8 s, 130 MB/s
1187162112 bytes (1.2 GB, 1.1 GiB) copied, 9 s, 132 MB/s
1289094144 bytes (1.3 GB, 1.2 GiB) copied, 10 s, 129 MB/s
1424950272 bytes (1.4 GB, 1.3 GiB) copied, 11 s, 130 MB/s
1537324032 bytes (1.5 GB, 1.4 GiB) copied, 12 s, 128 MB/s
1672166400 bytes (1.7 GB, 1.6 GiB) copied, 13 s, 129 MB/s
1794932736 bytes (1.8 GB, 1.7 GiB) copied, 14 s, 128 MB/s
1919382528 bytes (1.9 GB, 1.8 GiB) copied, 15 s, 128 MB/s
2061219840 bytes (2.1 GB, 1.9 GiB) copied, 16 s, 129 MB/s
2162989056 bytes (2.2 GB, 2.0 GiB) copied, 17 s, 127 MB/s
2267735040 bytes (2.3 GB, 2.1 GiB) copied, 18 s, 126 MB/s
2390962176 bytes (2.4 GB, 2.2 GiB) copied, 19 s, 126 MB/s
2509243392 bytes (2.5 GB, 2.3 GiB) copied, 20 s, 125 MB/s
2645179392 bytes (2.6 GB, 2.5 GiB) copied, 21 s, 126 MB/s
2790177792 bytes (2.8 GB, 2.6 GiB) copied, 22 s, 127 MB/s
2885956608 bytes (2.9 GB, 2.7 GiB) copied, 23 s, 125 MB/s
3024540672 bytes (3.0 GB, 2.8 GiB) copied, 24 s, 126 MB/s
3132251136 bytes (3.1 GB, 2.9 GiB) copied, 25 s, 125 MB/s
3258006528 bytes (3.3 GB, 3.0 GiB) copied, 26 s, 125 MB/s
dd: error writing '/tmp/test_mount/test_file': No space left on device
1093967+0 records in
1093966+0 records out
3360665600 bytes (3.4 GB, 3.1 GiB) copied, 26.8791 s, 125 MB/s

INFO: [2022-05-19 10:41:54] Syncing mount point with params cmd = sync /tmp/test_mount
INFO: [2022-05-19 10:41:54] Running: 'sync /tmp/test_mount'...


INFO: [2022-05-19 10:41:55] Removing test file with params cmd = rm -f /tmp/test_mount/test_file
INFO: [2022-05-19 10:41:55] Running: 'rm -f /tmp/test_mount/test_file'...


INFO: [2022-05-19 10:41:56] Syncing mount point with params cmd = sync /tmp/test_mount
INFO: [2022-05-19 10:41:56] Running: 'sync /tmp/test_mount'...


INFO: [2022-05-19 10:41:56] Sending trim with params cmd = fstrim /tmp/test_mount
INFO: [2022-05-19 10:41:56] Running: 'fstrim /tmp/test_mount'...


INFO: [2022-05-19 10:41:56] Checking logs for errors. with params since = -351

INFO: [2022-05-19 10:41:56] Umounting/tmp/test_mount with params mountpoint = /tmp/test_mount
INFO: [2022-05-19 10:41:56] Running: 'umount /tmp/test_mount'...


INFO: [2022-05-19 10:41:56] Removing mount dir with params dir_name = /tmp/test_mount

INFO: [2022-05-19 10:41:56] Removing VG 'vgtest' with params vg_name = vgtest, force = True
INFO: [2022-05-19 10:41:56] Running: 'vgremove --force vgtest'...
  Logical volume "testvol" successfully removed
  Volume group "vgtest" successfully removed
  WARNING: Device /dev/ram0 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram1 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram2 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram3 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram4 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram5 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram6 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram7 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram8 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram9 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram10 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram11 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram12 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram13 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram14 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram15 not initialized in udev database even after waiting 10000000 microseconds.

INFO: [2022-05-19 10:44:37] Removing PV  /dev/loop1p1 with params pv_name =  /dev/loop1p1
INFO: [2022-05-19 10:47:17] Running: 'pvremove  /dev/loop1p1'...
  Labels on physical volume "/dev/loop1p1" successfully wiped.
  WARNING: Device /dev/ram0 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram1 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram2 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram3 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram4 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram5 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram6 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram7 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram8 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram9 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram10 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram11 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram12 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram13 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram14 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram15 not initialized in udev database even after waiting 10000000 microseconds.

INFO: [2022-05-19 10:49:58] Removing PV  /dev/loop1p5 with params pv_name =  /dev/loop1p5
INFO: [2022-05-19 10:52:39] Running: 'pvremove  /dev/loop1p5'...
  Labels on physical volume "/dev/loop1p5" successfully wiped.
  WARNING: Device /dev/ram0 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram1 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram2 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram3 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram4 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram5 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram6 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram7 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram8 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram9 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram10 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram11 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram12 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram13 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram14 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram15 not initialized in udev database even after waiting 10000000 microseconds.

INFO: [2022-05-19 10:55:19] Removing PV  /dev/loop1p8 with params pv_name =  /dev/loop1p8
INFO: [2022-05-19 10:58:00] Running: 'pvremove  /dev/loop1p8'...
  Labels on physical volume "/dev/loop1p8" successfully wiped.
  WARNING: Device /dev/ram0 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram1 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram2 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram3 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram4 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram5 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram6 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram7 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram8 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram9 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram10 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram11 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram12 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram13 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram14 not initialized in udev database even after waiting 10000000 microseconds.
  WARNING: Device /dev/ram15 not initialized in udev database even after waiting 10000000 microseconds.

INFO: [2022-05-19 11:00:41] Removing PV  /dev/loop1p9 with params pv_name =  /dev/loop1p9


I tested the case 10 times but can not reproduce by manual, and just hit it in    beaker job.


Actual results:
Hit WRANING

Expected results:
no WRANING and timeout 

Additional info:

beaker job
https://beaker.engineering.redhat.com/recipes/11995836#task144632149
https://beaker.engineering.redhat.com/recipes/11981788#task144500845

Comment 1 guazhang@redhat.com 2022-05-20 01:33:41 UTC
Created attachment 1881492 [details]
sosreport-kvm-04-guest03-2022-05-19-foppyfh.tar.xz

Comment 4 Ben Cotton 2022-08-09 13:16:28 UTC
This bug appears to have been reported against 'rawhide' during the Fedora Linux 37 development cycle.
Changing version to 37.

Comment 5 Zdenek Kabelac 2022-08-10 13:32:23 UTC
ATM I could hardly guess what's wrong here.

Devices  /dev/ramXXX are usually created by i.e.  'modprobe  rd_size=xxxxxx'

It's unclear how do you get them in your case and also why your  'udevdb' does not get correct info about those devices in the moment 'lvm2' is being executed.
The fact we repeatadly wait for each individual 'uninitialized' device is kind of unpleasant and will be surely improved in some future instance of lvm2 - but it's not your actual problem.

You need to figure out what's wrong with your systemd-udevd in your particular machine - lvm2 basically only informs you about problems on udev db side.

Since you are working on 'rawhide' possible this might have been temporary defect in some rawhide systemd package release ?

So please reset with freshly upgraded system.

Also your 'sosreport' has no sign about /dev/ram devices - so hard to give any further advices here.

Comment 6 guazhang@redhat.com 2022-08-11 01:59:05 UTC
I'm not sure why this warning occurred here, and the bug just hit in CKI regression testing .

Don't run any command like 'modprobe  rd_size=xxxxxx' in the testing.

how to get helpful log since the bug hit again , or what logs should be saved ?


Note You need to log in before you can comment on or make changes to this bug.