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=1SamOn Wed, Apr 7, 2021 at 5:19 PM Sam Eiderman <sameid@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 monitorFor some reason the following process didn't return anything (but succeeded):/sbin/dmsetup splitname --nameprefixes --noheadings --rows rhel-rootHowever:/sbin/dmsetup splitname --nameprefixes --noheadings --rows rhel-swapCorrectly returned:DM_VG_NAME='rhel'DM_LV_NAME='swap'DM_LV_LAYER=''I wonder whyOn Wed, Apr 7, 2021 at 4:36 PM Sam Eiderman <sameid@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 executionsAttached output (~300KB).Thanks!SamOn Tue, Apr 6, 2021 at 7:29 PM Sam Eiderman <sameid@google.com> wrote:FYI, in debian the rules are a bit in a different flavor:01-md-raid-creating.rules
50-firmware.rules50-udev-default.rules55-dm.rules
56-lvm.rules60-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.rulesSo maybe there is some difference here.SamOn Mon, Apr 5, 2021 at 9:31 PM Richard W.M. Jones <rjones@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/