[Libguestfs] LVM flakey failures
Sam Eiderman
sameid at google.com
Wed Apr 7 17:59:06 UTC 2021
In another run, dmsetup splitname does work on rhel-root but still no
device under /dev (different bug?)
I also added "udevadm info /dev/mapper/*-*" line after the pvscan
+ lvm pvscan --cache --activate ay
:0002632: sd-device-monitor: Passed 133 byte to netlink monitor
:0003312: Device (SEQNUM=992, ACTION=add) is queued
:0003312: Processing device (SEQNUM=992, ACTION=add)
:0003312: Device (SEQNUM=992, ACTION=add) processed:0003312:
sd-device-monitor: Passed 133 byte to netlink monitor
device-mapper: Device (SEQNUM=993, ACTION=add) is queued
device-mapper: Processing device (SEQNUM=993, ACTION=add)
device-mapper: NAME 'mapper/control' /lib/udev/rules.d/55-dm.rules:31
device-mapper: sd-device-monitor: Passed 194 byte to netlink monitor
:0003312: sd-device-monitor: Passed 133 byte to netlink monitor
device-mapper: Handling device node '/dev/mapper/control', devnum=c10:236,
mode=0600, uid=0, gid=0
device-mapper: Preserve permissions of /dev/mapper/control, 020600, uid=0,
gid=0
device-mapper: Creating symlink '/dev/char/10:236' to '../mapper/control'
device-mapper: sd-device: Created empty file '/run/udev/data/c10:236' for
'/devices/virtual/misc/device-mapper'
device-mapper: Device (SEQNUM=993, ACTION=add) processed
device-mapper: sd-device-monitor: Passed 194 byte to netlink monitor
253:0: Device (SEQNUM=994, ACTION=add) is queued
253:0: Processing device (SEQNUM=994, ACTION=add)
253:0: Device (SEQNUM=994, ACTION=add) processed
253:0: sd-device-monitor: Passed 137 byte to netlink monitor253:0:
sd-device-monitor: Passed 137 byte to netlink monitor
dm-0: Device (SEQNUM=995, ACTION=add) is queued
dm-0: Processing device (SEQNUM=995, ACTION=add)
dm-0: GROUP 0 /lib/udev/rules.d/50-udev-default.rules:59dm-0:
sd-device-monitor: Passed 189 byte to netlink monitor
dm-0: Handling device node '/dev/dm-0', devnum=b253:0, mode=0600, uid=0,
gid=0
dm-0: Preserve permissions of /dev/dm-0, 060600, uid=0, gid=0dm-0: Device
(SEQNUM=996, ACTION=change) is queued
dm-0: Creating symlink '/dev/block/253:0' to '../dm-0'
dm-0: sd-device: Created db file '/run/udev/data/b253:0' for
'/devices/virtual/block/dm-0'253:1: Device (SEQNUM=997, ACTION=add) is
queued
dm-0: Device (SEQNUM=995, ACTION=add) processed
dm-0: sd-device-monitor: Passed 328 byte to netlink monitor
253:1: Processing device (SEQNUM=997, ACTION=add)
253:1: Device (SEQNUM=997, ACTION=add) processed253:1: sd-device-monitor:
Passed 137 byte to netlink monitor
dm-0: Processing device (SEQNUM=996, ACTION=change)
dm-0: IMPORT '/sbin/dmsetup udevflags 6340809'
/lib/udev/rules.d/55-dm.rules:52
253:1: sd-device-monitor: Passed 137 byte to netlink monitor
dm-0: sd-device-monitor: Passed 210 byte to netlink monitor
Starting '/sbin/dmsetup udevflags 6340809'
Successfully forked off '(spawn)' as PID 137.
dm-1: Device (SEQNUM=998, ACTION=add) is queued
dm-1: Processing device (SEQNUM=998, ACTION=add)dm-1: sd-device-monitor:
Passed 189 byte to netlink monitor
dm-1: Device (SEQNUM=999, ACTION=change) is queued
dm-1: GROUP 0 /lib/udev/rules.d/50-udev-default.rules:59
dm-1: Handling device node '/dev/dm-1', devnum=b253:1, mode=0600, uid=0,
gid=0'/sbin/dmsetup udevflags 6340809'(out)
'DM_UDEV_DISABLE_LIBRARY_FALLBACK_FLAG='1''
dm-1: Preserve permissions of /dev/dm-1, 060600, uid=0, gid=0
dm-1: Creating symlink '/dev/block/253:1' to '../dm-1'
'/sbin/dmsetup udevflags 6340809'(out) 'DM_UDEV_PRIMARY_SOURCE_FLAG='1''
Process '/sbin/dmsetup udevflags 6340809' succeeded.
dm-0: LINK 'mapper/rhel-swap' /lib/udev/rules.d/55-dm.rules:136dm-1:
sd-device: Created db file '/run/udev/data/b253:1' for
'/devices/virtual/block/dm-1'
dm-0: IMPORT '/sbin/dmsetup -v splitname --nameprefixes --noheadings --rows
rhel-swap' /lib/udev/rules.d/56-lvm.rules:21
dm-1: Device (SEQNUM=998, ACTION=add) processed
dm-1: sd-device-monitor: Passed 328 byte to netlink monitor
Starting '/sbin/dmsetup -v splitname --nameprefixes --noheadings --rows
rhel-swap'
dm-1: sd-device-monitor: Passed 210 byte to netlink monitor
dm-1: Processing device (SEQNUM=999, ACTION=change)
Successfully forked off '(spawn)' as PID 138.
'/sbin/dmsetup -v splitname --nameprefixes --noheadings --rows
rhel-swap'(out) 'DM_VG_NAME='rhel''
'/sbin/dmsetup -v splitname --nameprefixes --noheadings --rows
rhel-swap'(out) 'DM_LV_NAME='swap''
'/sbin/dmsetup -v splitname --nameprefixes --noheadings --rows
rhel-swap'(out) 'DM_LV_LAYER='''dm-1: IMPORT '/sbin/dmsetup udevflags
6340809' /lib/udev/rules.d/55-dm.rules:52
Starting '/sbin/dmsetup udevflags 6340809'
Successfully forked off '(spawn)' as PID 139.
Process '/sbin/dmsetup -v splitname --nameprefixes --noheadings --rows
rhel-swap' succeeded.
dm-0: LINK 'rhel/swap' /lib/udev/rules.d/56-lvm.rules:47Process
'/sbin/dmsetup udevflags 6340809' succeeded.
dm-0: LINK 'disk/by-id/dm-name-rhel-swap'
/lib/udev/rules.d/60-persistent-storage-dm.rules:17
dm-0: LINK
'disk/by-id/dm-uuid-LVM-x06hRU2yvmTSN0lIa6z1DKEgd9r51XboEVgg8YdhPyNGooshjsJZFwDraGqJBAAp'
/lib/udev/rules.d/60-persistent-storage-dm.rules:18
dm-0: IMPORT builtin 'blkid'
/lib/udev/rules.d/60-persistent-storage-dm.rules:23
dm-1: LINK 'mapper/rhel-root' /lib/udev/rules.d/55-dm.rules:136
dm-0: Probe /dev/dm-0 with raid and offset=0
dm-1: IMPORT '/sbin/dmsetup -v splitname --nameprefixes --noheadings --rows
rhel-root' /lib/udev/rules.d/56-lvm.rules:21
Starting '/sbin/dmsetup -v splitname --nameprefixes --noheadings --rows
rhel-root'
Successfully forked off '(spawn)' as PID 140.
'/sbin/dmsetup -v splitname --nameprefixes --noheadings --rows
rhel-root'(out) 'DM_VG_NAME='rhel''
'/sbin/dmsetup -v splitname --nameprefixes --noheadings --rows
rhel-root'(out) 'DM_LV_NAME='root''dm-0: LINK
'disk/by-uuid/7ed3e932-edd1-4d73-9272-5a7c05ba84d5'
/lib/udev/rules.d/60-persistent-storage-dm.rules:25
'/sbin/dmsetup -v splitname --nameprefixes --noheadings --rows
rhel-root'(out) 'DM_LV_LAYER='''
dm-0: RUN '/sbin/dmsetup udevcomplete $env{DM_COOKIE}'
/lib/udev/rules.d/95-dm-notify.rules:12
dm-0: Handling device node '/dev/dm-0', devnum=b253:0, mode=0600, uid=0,
gid=0
Process '/sbin/dmsetup -v splitname --nameprefixes --noheadings --rows
rhel-root' succeeded.
dm-1: RUN '/sbin/dmsetup udevcomplete $env{DM_COOKIE}'
/lib/udev/rules.d/95-dm-notify.rules:12
dm-0: Preserve already existing symlink '/dev/block/253:0' to '../dm-0'
dm-1: Handling device node '/dev/dm-1', devnum=b253:1, mode=0600, uid=0,
gid=0
dm-0: Creating symlink '/dev/disk/by-id/dm-name-rhel-swap' to '../../dm-0'
dm-0: Creating symlink
'/dev/disk/by-uuid/7ed3e932-edd1-4d73-9272-5a7c05ba84d5' to '../../dm-0'
dm-1: Preserve already existing symlink '/dev/block/253:1' to '../dm-1'
dm-0: Creating symlink '/dev/mapper/rhel-swap' to '../dm-0'
dm-1: Creating symlink '/dev/mapper/rhel-root' to '../dm-1'
dm-0: Creating symlink
'/dev/disk/by-id/dm-uuid-LVM-x06hRU2yvmTSN0lIa6z1DKEgd9r51XboEVgg8YdhPyNGooshjsJZFwDraGqJBAAp'
to '../../dm-0'dm-1: sd-device: Created db file '/run/udev/data/b253:1' for
'/devices/virtual/block/dm-1'
dm-0: Creating symlink '/dev/rhel/swap' to '../dm-0'
dm-0: sd-device: Created db file '/run/udev/data/b253:0' for
'/devices/virtual/block/dm-0'
Starting '/sbin/dmsetup udevcomplete 6340809'
Successfully forked off '(spawn)' as PID 141.
Starting '/sbin/dmsetup udevcomplete 6340809'
Successfully forked off '(spawn)' as PID 142.Process '/sbin/dmsetup
udevcomplete 6340809' succeeded.
dm-1: Device (SEQNUM=999, ACTION=change) processed
dm-1: sd-device-monitor: Passed 555 byte to netlink monitor
2 logical volume(s) in volume group "rhel" now active
Process '/sbin/dmsetup udevcomplete 6340809' succeeded.
dm-0: Adding watch on '/dev/dm-0'
dm-0: sd-device: Created db file '/run/udev/data/b253:0' for
'/devices/virtual/block/dm-0'
dm-0: Device (SEQNUM=996, ACTION=change) processed
dm-0: sd-device-monitor: Passed 901 byte to netlink monitor
+ udevadm info /dev/mapper/rhel-root /dev/mapper/rhel-swap
P: /devices/virtual/block/dm-1
N: dm-1
L: 0
S: mapper/rhel-root
E: DEVPATH=/devices/virtual/block/dm-1
E: DEVNAME=/dev/dm-1
E: DEVTYPE=disk
E: MAJOR=253
E: MINOR=1
E: SUBSYSTEM=block
E: USEC_INITIALIZED=10585563
E: DM_UDEV_DISABLE_SUBSYSTEM_RULES_FLAG=1
E: DM_UDEV_DISABLE_DISK_RULES_FLAG=1
E: DM_UDEV_DISABLE_OTHER_RULES_FLAG=1
E: DM_NAME=rhel-root
E:
DM_UUID=LVM-x06hRU2yvmTSN0lIa6z1DKEgd9r51XboJq5285kndk6TL6cxXmB4CccqViTqwI6r
E: DM_SUSPENDED=0
E: DM_UDEV_RULES=1
E: DM_UDEV_RULES_VSN=2
E: DM_VG_NAME=rhel
E: DM_LV_NAME=root
E: DEVLINKS=/dev/mapper/rhel-root
E: TAGS=:systemd:
P: /devices/virtual/block/dm-0
N: dm-0
L: 0
S: disk/by-uuid/7ed3e932-edd1-4d73-9272-5a7c05ba84d5
S: mapper/rhel-swap
S: disk/by-id/dm-name-rhel-swap
S: rhel/swap
S:
disk/by-id/dm-uuid-LVM-x06hRU2yvmTSN0lIa6z1DKEgd9r51XboEVgg8YdhPyNGooshjsJZFwDraGqJBAAp
E: DEVPATH=/devices/virtual/block/dm-0
E: DEVNAME=/dev/dm-0
E: DEVTYPE=disk
E: MAJOR=253
E: MINOR=0
E: SUBSYSTEM=block
E: USEC_INITIALIZED=10478639
E: DM_UDEV_DISABLE_LIBRARY_FALLBACK_FLAG=1
E: DM_UDEV_PRIMARY_SOURCE_FLAG=1
E: DM_ACTIVATION=1
E: DM_NAME=rhel-swap
E:
DM_UUID=LVM-x06hRU2yvmTSN0lIa6z1DKEgd9r51XboEVgg8YdhPyNGooshjsJZFwDraGqJBAAp
E: DM_SUSPENDED=0
E: DM_UDEV_RULES=1
E: DM_UDEV_RULES_VSN=2
E: DM_VG_NAME=rhel
E: DM_LV_NAME=swap
E: ID_FS_UUID=7ed3e932-edd1-4d73-9272-5a7c05ba84d5
E: ID_FS_UUID_ENC=7ed3e932-edd1-4d73-9272-5a7c05ba84d5
E: ID_FS_VERSION=1
E: ID_FS_TYPE=swap
E: ID_FS_USAGE=other
E: DEVLINKS=/dev/disk/by-uuid/7ed3e932-edd1-4d73-9272-5a7c05ba84d5
/dev/mapper/rhel-swap /dev/disk/by-id/dm-name-rhel-swap /dev/rhel/swap
/dev/disk/by-id/dm-uuid-LVM-x06hRU2yvmTSN0lIa6z1DKEgd9r51XboEVgg8YdhPyNGooshjsJZFwDraGqJBAAp
E: TAGS=:systemd:
In this run for some reason lvm has set the following on the device:
E: DM_UDEV_DISABLE_SUBSYSTEM_RULES_FLAG=1
Sam
On Wed, Apr 7, 2021 at 5:19 PM Sam Eiderman <sameid at google.com> wrote:
> I think this is the interesting part:
>
> + lvm pvscan --cache --activate ay
> device-mapper: Device (SEQNUM=993, ACTION=add) is queued
> device-mapper: sd-device-monitor: Passed 193 byte to netlink monitor
> device-mapper: Processing device (SEQNUM=993, ACTION=add)
> device-mapper: NAME 'mapper/control' /lib/udev/rules.d/55-dm.rules:31
> device-mapper: Handling device node '/dev/mapper/control', devnum=c10:236, mode=0600, uid=0, gid=0
> device-mapper: Preserve permissions of /dev/mapper/control, 020600, uid=0, gid=0
> device-mapper: Creating symlink '/dev/char/10:236' to '../mapper/control'
> device-mapper: sd-device: Created empty file '/run/udev/data/c10:236' for '/devices/virtual/misc/device-mapper'
> device-mapper: Device (SEQNUM=993, ACTION=add) processed
> device-mapper: sd-device-monitor: Passed 193 byte to netlink monitor
> 253:0: Device (SEQNUM=994, ACTION=add) is queued
> 253:0: sd-device-monitor: Passed 136 byte to netlink monitor
> 253:0: Processing device (SEQNUM=994, ACTION=add)
> 253:0: Device (SEQNUM=994, ACTION=add) processed
> 253:0: sd-device-monitor: Passed 136 byte to netlink monitor
> dm-0: Device (SEQNUM=995, ACTION=add) is queued
> dm-0: sd-device-monitor: Passed 188 byte to netlink monitor
> dm-0: Processing device (SEQNUM=995, ACTION=add)
> dm-0: GROUP 0 /lib/udev/rules.d/50-udev-default.rules:59
> dm-0: Handling device node '/dev/dm-0', devnum=b253:0, mode=0600, uid=0, gid=0
> dm-0: Preserve permissions of /dev/dm-0, 060600, uid=0, gid=0
> dm-0: Creating symlink '/dev/block/253:0' to '../dm-0'dm-0: Device (SEQNUM=996, ACTION=change) is queued
> 253:1: Device (SEQNUM=997, ACTION=add) is queued
> 253:1: Processing device (SEQNUM=997, ACTION=add)
> 253:1: Device (SEQNUM=997, ACTION=add) processed
> 253:1: sd-device-monitor: Passed 136 byte to netlink monitor
> 253:1: sd-device-monitor: Passed 136 byte to netlink monitor
> dm-1: Device (SEQNUM=998, ACTION=add) is queued
> dm-1: Processing device (SEQNUM=998, ACTION=add)
> dm-1: GROUP 0 /lib/udev/rules.d/50-udev-default.rules:59
> dm-1: Handling device node '/dev/dm-1', devnum=b253:1, mode=0600, uid=0, gid=0
> dm-1: Preserve permissions of /dev/dm-1, 060600, uid=0, gid=0
> dm-1: Creating symlink '/dev/block/253:1' to '../dm-1'
> dm-1: sd-device: Created db file '/run/udev/data/b253:1' for '/devices/virtual/block/dm-1'
> dm-1: Device (SEQNUM=998, ACTION=add) processeddm-1: sd-device-monitor: Passed 188 byte to netlink monitor
> dm-1: Device (SEQNUM=999, ACTION=change) is queued
>
> dm-0: sd-device: Created db file '/run/udev/data/b253:0' for '/devices/virtual/block/dm-0'
> dm-0: Device (SEQNUM=995, ACTION=add) processed
> dm-0: sd-device-monitor: Passed 327 byte to netlink monitor
> dm-0: sd-device-monitor: Passed 209 byte to netlink monitor
>
> dm-1: sd-device-monitor: Passed 327 byte to netlink monitordm-0: Processing device (SEQNUM=996, ACTION=change)
> dm-0: IMPORT '/sbin/dmsetup udevflags 6336918' /lib/udev/rules.d/55-dm.rules:52
> Starting '/sbin/dmsetup udevflags 6336918'
> Successfully forked off '(spawn)' as PID 136.
>
> dm-1: sd-device-monitor: Passed 209 byte to netlink monitor
> dm-1: Processing device (SEQNUM=999, ACTION=change)
> dm-1: IMPORT '/sbin/dmsetup udevflags 6336918' /lib/udev/rules.d/55-dm.rules:52
> Starting '/sbin/dmsetup udevflags 6336918'
> Successfully forked off '(spawn)' as PID 137.
> '/sbin/dmsetup udevflags 6336918'(out) 'DM_UDEV_DISABLE_LIBRARY_FALLBACK_FLAG='1''
> '/sbin/dmsetup udevflags 6336918'(out) 'DM_UDEV_PRIMARY_SOURCE_FLAG='1''
> Process '/sbin/dmsetup udevflags 6336918' succeeded.
> dm-0: LINK 'mapper/rhel-swap' /lib/udev/rules.d/55-dm.rules:136
> dm-0: IMPORT '/sbin/dmsetup splitname --nameprefixes --noheadings --rows rhel-swap' /lib/udev/rules.d/56-lvm.rules:21
> Starting '/sbin/dmsetup splitname --nameprefixes --noheadings --rows rhel-swap'
> Successfully forked off '(spawn)' as PID 138.'/sbin/dmsetup udevflags 6336918'(out) 'DM_UDEV_DISABLE_LIBRARY_FALLBACK_FLAG='1''
> '/sbin/dmsetup udevflags 6336918'(out) 'DM_UDEV_PRIMARY_SOURCE_FLAG='1''
>
> '/sbin/dmsetup splitname --nameprefixes --noheadings --rows rhel-swap'(out) 'DM_VG_NAME='rhel''
> '/sbin/dmsetup splitname --nameprefixes --noheadings --rows rhel-swap'(out) 'DM_LV_NAME='swap''
> '/sbin/dmsetup splitname --nameprefixes --noheadings --rows rhel-swap'(out) 'DM_LV_LAYER='''
> Process '/sbin/dmsetup splitname --nameprefixes --noheadings --rows rhel-swap' succeeded.Process '/sbin/dmsetup udevflags 6336918' succeeded.
> dm-1: LINK 'mapper/rhel-root' /lib/udev/rules.d/55-dm.rules:136
> dm-1: IMPORT '/sbin/dmsetup splitname --nameprefixes --noheadings --rows rhel-root' /lib/udev/rules.d/56-lvm.rules:21
> Starting '/sbin/dmsetup splitname --nameprefixes --noheadings --rows rhel-root'
> Successfully forked off '(spawn)' as PID 139.
>
> dm-0: LINK 'rhel/swap' /lib/udev/rules.d/56-lvm.rules:47
> dm-0: LINK 'disk/by-id/dm-name-rhel-swap' /lib/udev/rules.d/60-persistent-storage-dm.rules:17
> dm-0: LINK 'disk/by-id/dm-uuid-LVM-x06hRU2yvmTSN0lIa6z1DKEgd9r51XboEVgg8YdhPyNGooshjsJZFwDraGqJBAAp' /lib/udev/rules.d/60-persistent-storage-dm.rules:18
> dm-0: IMPORT builtin 'blkid' /lib/udev/rules.d/60-persistent-storage-dm.rules:23
> dm-0: Probe /dev/dm-0 with raid and offset=0
> Process '/sbin/dmsetup splitname --nameprefixes --noheadings --rows rhel-root' succeeded.
> dm-1: RUN '/sbin/dmsetup udevcomplete $env{DM_COOKIE}' /lib/udev/rules.d/95-dm-notify.rules:12
> dm-1: Handling device node '/dev/dm-1', devnum=b253:1, mode=0600, uid=0, gid=0
> dm-1: Preserve already existing symlink '/dev/block/253:1' to '../dm-1'
> dm-1: Creating symlink '/dev/mapper/rhel-root' to '../dm-1'
> dm-1: sd-device: Created db file '/run/udev/data/b253:1' for '/devices/virtual/block/dm-1'
> Starting '/sbin/dmsetup udevcomplete 6336918'
> Successfully forked off '(spawn)' as PID 140.
> dm-0: LINK 'disk/by-uuid/7ed3e932-edd1-4d73-9272-5a7c05ba84d5' /lib/udev/rules.d/60-persistent-storage-dm.rules:25
> Process '/sbin/dmsetup udevcomplete 6336918' succeeded.
> dm-1: Device (SEQNUM=999, ACTION=change) processed
> dm-1: sd-device-monitor: Passed 556 byte to netlink monitor
> dm-0: RUN '/sbin/dmsetup udevcomplete $env{DM_COOKIE}' /lib/udev/rules.d/95-dm-notify.rules:12
> dm-0: Handling device node '/dev/dm-0', devnum=b253:0, mode=0600, uid=0, gid=0
> dm-0: Preserve already existing symlink '/dev/block/253:0' to '../dm-0'
> dm-0: Creating symlink '/dev/rhel/swap' to '../dm-0'
> dm-0: Creating symlink '/dev/disk/by-id/dm-uuid-LVM-x06hRU2yvmTSN0lIa6z1DKEgd9r51XboEVgg8YdhPyNGooshjsJZFwDraGqJBAAp' to '../../dm-0'
> dm-0: Creating symlink '/dev/disk/by-uuid/7ed3e932-edd1-4d73-9272-5a7c05ba84d5' to '../../dm-0'
> dm-0: Creating symlink '/dev/mapper/rhel-swap' to '../dm-0'
> dm-0: Creating symlink '/dev/disk/by-id/dm-name-rhel-swap' to '../../dm-0'
> dm-0: sd-device: Created db file '/run/udev/data/b253:0' for '/devices/virtual/block/dm-0'
> Starting '/sbin/dmsetup udevcomplete 6336918'
> Successfully forked off '(spawn)' as PID 141.
> 2 logical volume(s) in volume group "rhel" now active
> Process '/sbin/dmsetup udevcomplete 6336918' succeeded.
> dm-0: Adding watch on '/dev/dm-0'
> dm-0: sd-device: Created db file '/run/udev/data/b253:0' for '/devices/virtual/block/dm-0'
> dm-0: Device (SEQNUM=996, ACTION=change) processed
> dm-0: sd-device-monitor: Passed 900 byte to netlink monitor
>
>
> For some reason the following process didn't return anything (but
> succeeded):
>
> /sbin/dmsetup splitname --nameprefixes --noheadings --rows rhel-root
>
> However:
>
> /sbin/dmsetup splitname --nameprefixes --noheadings --rows rhel-swap
>
> Correctly returned:
>
> DM_VG_NAME='rhel'
> DM_LV_NAME='swap'
> DM_LV_LAYER=''
>
> I wonder why
>
> On Wed, Apr 7, 2021 at 4:36 PM Sam Eiderman <sameid at google.com> wrote:
>
>> I managed to get a reproduction with udevd --debug.
>>
>> I just waited for g.inspect_os() (per g.launch()) to fail return anything
>> (/dev/rhel/root symlink doesn't exist) in 32 concurrent executions
>>
>> Attached output (~300KB).
>>
>> Thanks!
>> Sam
>>
>> On Tue, Apr 6, 2021 at 7:29 PM Sam Eiderman <sameid at google.com> wrote:
>>
>>> FYI, in debian the rules are a bit in a different flavor:
>>>
>>> 01-md-raid-creating.rules
>>> 50-firmware.rules
>>> 50-udev-default.rules
>>>
>>> 55-dm.rules
>>> 56-lvm.rules
>>>
>>> 60-block.rules
>>> 60-cdrom_id.rules
>>> 60-drm.rules
>>> 60-evdev.rules
>>> 60-input-id.rules
>>> 60-persistent-alsa.rules
>>> 60-persistent-input.rules
>>> 60-persistent-storage-dm.rules
>>> 60-persistent-storage-tape.rules
>>> 60-persistent-storage.rules
>>> 60-persistent-v4l.rules
>>> 60-sensor.rules
>>> 60-serial.rules
>>> 63-md-raid-arrays.rules
>>> 64-btrfs-dm.rules
>>> 64-btrfs.rules
>>> 64-md-raid-assembly.rules
>>> 69-lvm-metad.rules
>>> 69-md-clustered-confirm-device.rules
>>> 70-joystick.rules
>>> 70-mouse.rules
>>> 70-power-switch.rules
>>> 70-touchpad.rules
>>> 70-uaccess.rules
>>> 71-seat.rules
>>> 73-seat-late.rules
>>> 73-special-net-names.rules
>>> 73-usb-net-by-mac.rules
>>> 75-net-description.rules
>>> 75-probe_mtd.rules
>>> 78-sound-card.rules
>>> 80-debian-compat.rules
>>> 80-drivers.rules
>>> 80-net-setup-link.rules
>>> 82-gfs2-withdraw.rules
>>> 85-hwclock.rules
>>> 95-dm-notify.rules
>>> 99-systemd.rules
>>>
>>> So maybe there is some difference here.
>>>
>>> Sam
>>>
>>> On Mon, Apr 5, 2021 at 9:31 PM Richard W.M. Jones <rjones at redhat.com>
>>> wrote:
>>>
>>>> On Mon, Apr 05, 2021 at 05:49:17PM +0300, Sam Eiderman wrote:
>>>> > Yes, attached below (it's quite long)
>>>>
>>>> Thanks - just looking at the lines where the /dev/rhel/swap
>>>> device appears or its various synonyms:
>>>>
>>>> > 2021-03-07 10:58:46 T libguestfs - 0 - appliance - drwxr-xr-x 2 0 0
>>>> 60 Mar 7 10:58 rhel
>>>> [...]
>>>> > 2021-03-07 10:58:47 T libguestfs - 0 - appliance - /dev/mapper:
>>>> > 2021-03-07 10:58:47 T libguestfs - 0 - appliance - total 0
>>>> > 2021-03-07 10:58:47 T libguestfs - 0 - appliance - crw------- 1 0 0
>>>> 10, 236 Mar
>>>> > 7 10:58 control
>>>> > 2021-03-07 10:58:47 T libguestfs - 0 - appliance - lrwxrwxrwx 1 0 0
>>>> 7 Mar
>>>> > 7 10:58 rhel-root -> ../dm-2
>>>> > 2021-03-07 10:58:47 T libguestfs - 0 - appliance - lrwxrwxrwx 1 0 0
>>>> 7 Mar
>>>> > 7 10:58 rhel-swap -> ../dm-1
>>>>
>>>> This is fairly early on during appliance boot where the init script is
>>>> listing out /dev/ recursively
>>>> (
>>>> https://github.com/libguestfs/libguestfs/blob/b18ac489db76a700f2168ae6eb64e9d450613a27/appliance/init#L159
>>>> ).
>>>> This is also after we did udevadm settle in the init script. It's
>>>> interesting that at this point /dev/mapper/rhel-swap exists correctly,
>>>> but /dev/rhel/ is an empty directory.
>>>>
>>>> That's very much not expected ...
>>>>
>>>> A bit later in the init script we list out PVs/VGs/LVs and everything
>>>> looks normal:
>>>>
>>>> > 2021-03-07 10:58:47 T libguestfs - 0 - appliance - + lvm pvs
>>>> > 2021-03-07 10:58:47 T libguestfs - 0 - appliance - PV VG
>>>> Fmt
>>>> > Attr PSize PFree
>>>> > 2021-03-07 10:58:47 T libguestfs - 0 - appliance - /dev/sda2 rhel
>>>> lvm2
>>>> > a-- <15.00g 0
>>>> > 2021-03-07 10:58:47 T libguestfs - 0 - appliance - /dev/sdb
>>>> vg_myvg lvm2
>>>> > a-- 496.00m 0
>>>> > 2021-03-07 10:58:47 T libguestfs - 0 - appliance - + lvm vgs
>>>> > 2021-03-07 10:58:47 T libguestfs - 0 - appliance - VG #PV #LV
>>>> #SN Attr
>>>> > VSize VFree
>>>> > 2021-03-07 10:58:47 T libguestfs - 0 - appliance - rhel 1 2
>>>> 0 wz--n-
>>>> > <15.00g 0
>>>> > 2021-03-07 10:58:47 T libguestfs - 0 - appliance - vg_myvg 1 1
>>>> 0 wz--n-
>>>> > 496.00m 0
>>>> > 2021-03-07 10:58:47 T libguestfs - 0 - appliance - + lvm lvs
>>>> > 2021-03-07 10:58:48 T libguestfs - 0 - appliance - LV VG
>>>> Attr
>>>> > LSize Pool Origin Data% Meta% Move Log Cpy%Sync Convert
>>>> > 2021-03-07 10:58:48 T libguestfs - 0 - appliance - root rhel
>>>> -wi-a-----
>>>> > 13.39g
>>>> > 2021-03-07 10:58:48 T libguestfs - 0 - appliance - swap rhel
>>>> -wi-a-----
>>>> > 1.60g
>>>> > 2021-03-07 10:58:48 T libguestfs - 0 - appliance - lv_var vg_myvg
>>>> -wi-a-----
>>>> > 496.00m
>>>>
>>>> A little bit further on while we're executing the guestfs_inspect_os()
>>>> API call, we have this snippet:
>>>>
>>>> > 2021-03-07 10:58:49 T libguestfs - 0 - appliance - command: lvm 'lvs'
>>>> '-o'
>>>> > 'vg_name,lv_name' '-S' 'lv_role=public && lv_skip_activation!=yes'
>>>> > '--noheadings' '--separator' '/'
>>>> > 2021-03-07 10:58:49 T libguestfs - 0 - appliance - command: lvm
>>>> returned 0
>>>> > 2021-03-07 10:58:49 T libguestfs - 0 - appliance - command: lvm:
>>>> stdout:
>>>> > 2021-03-07 10:58:49 T libguestfs - 0 - appliance - rhel/root
>>>> > 2021-03-07 10:58:49 T libguestfs - 0 - appliance - rhel/swap
>>>> > 2021-03-07 10:58:49 T libguestfs - 0 - appliance - vg_myvg/lv_var
>>>> > 2021-03-07 10:58:49 T libguestfs - 0 - appliance - command: blkid
>>>> '-c' '/dev/
>>>> > null' '-o' 'value' '-s' 'TYPE' '/dev/rhel/root'
>>>> > 2021-03-07 10:58:49 T libguestfs - 0 - appliance - command: blkid
>>>> returned 0
>>>> > 2021-03-07 10:58:49 T libguestfs - 0 - appliance - command: blkid:
>>>> stdout:
>>>> > 2021-03-07 10:58:49 T libguestfs - 0 - appliance - xfs
>>>> > 2021-03-07 10:58:49 T libguestfs - 0 - appliance - command: blkid
>>>> '-c' '/dev/
>>>> > null' '-o' 'value' '-s' 'TYPE' '/dev/rhel/swap'
>>>> > 2021-03-07 10:58:49 T libguestfs - 0 - appliance - command: blkid
>>>> returned 2
>>>> > 2021-03-07 10:58:49 T libguestfs - 0 - appliance - command: blkid
>>>> '-c' '/dev/
>>>> > null' '-o' 'value' '-s' 'TYPE' '/dev/vg_myvg/lv_var'
>>>> > 2021-03-07 10:58:49 T libguestfs - 0 - appliance - command: blkid
>>>> returned 0
>>>> > 2021-03-07 10:58:49 T libguestfs - 0 - appliance - command: blkid:
>>>> stdout:
>>>> > 2021-03-07 10:58:49 T libguestfs - 0 - appliance - xfs
>>>>
>>>> If you look closely it's clear that /dev/rhel/root has been created,
>>>> /dev/vg_myvg/lv_var has been created (that was also an empty directory
>>>> earlier on), but /dev/rhel/swap has *not* been created--notice how the
>>>> blkid command exits with code 2.
>>>>
>>>> And obviously by the time we get down here ...
>>>>
>>>> > 2021-03-07 10:58:53 T libguestfs - 0 - appliance - rhel/root
>>>> > 2021-03-07 10:58:53 T libguestfs - 0 - appliance - rhel/swap
>>>> > 2021-03-07 10:58:53 T libguestfs - 0 - appliance - vg_myvg/lv_var
>>>> > 2021-03-07 10:58:53 T libguestfs - 0 - appliance - guestfsd: error:
>>>> stat: /dev/
>>>> > rhel/swap: No such file or directory
>>>>
>>>> ... it still doesn't exist.
>>>>
>>>> We ran a udevadm --debug settle command before this, so if it wasn't
>>>> going to be created because of a delayed udev event then I'd expect it
>>>> should have done.
>>>>
>>>> I'm not much closer to understanding why the /dev/VG/LV nodes are
>>>> created so much later/delayed than the /dev/mapper/VG-LV nodes. As
>>>> far as I can tell they should be created by udev
>>>> (/usr/lib/udev/rules.d/11-dm-lvm.rules in Fedora).
>>>>
>>>> Would suggest enabling udevadm debugging (uncomment #--debug in
>>>> appliance/init).
>>>>
>>>> It would also be good to have some more concrete reproducer: you might
>>>> have appliance/init kill PID 1 if /dev/rhel/swap does not exist, then
>>>> repeatedly run g.launch() to see if you can make it fail, all the time
>>>> while trying to capture the log of the failure with udev debugging
>>>> turned on.
>>>>
>>>> Rich.
>>>>
>>>> --
>>>> Richard Jones, Virtualization Group, Red Hat
>>>> http://people.redhat.com/~rjones
>>>> Read my programming and virtualization blog: http://rwmj.wordpress.com
>>>> virt-df lists disk usage of guests without needing to install any
>>>> software inside the virtual machine. Supports Linux and Windows.
>>>> http://people.redhat.com/~rjones/virt-df/
>>>>
>>>>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://listman.redhat.com/archives/libguestfs/attachments/20210407/38e69f17/attachment.htm>
More information about the Libguestfs
mailing list