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