Discussion:
device symlinks being removed
Patrick Hemmer
2014-08-15 23:46:21 UTC
Permalink
It seems I have some sort of race condition when using udev rules to set
up some device symlinks, but I'm not sure why.
I'm building EC2 boxes, and immediately after they boot, they add some
udev rules to create symlinks, and then call `udevadm trigger` to
process the rules. The problem is that during this procedure, sometimes
some of the links are missing. The udev debug log indicates the links
were created, and then subsequently removed.

The complete system log can be viewed at http://dpaste.com/1BN5FKA
However I've grabbed what look like the interesting lines, and have
included them at the bottom. Notice the ones such as

creating symlink '/dev/disk/ec2/vol-05b50706' to '../../xvda'

and

update old name, '/dev/disk/ec2/vol-05b50706' no longer belonging to
'/devices/vbd-2048/block/xvda'
no reference left, remove '/dev/disk/ec2/vol-05b50706'


My udev rule looks like this:

SUBSYSTEM=="block", SUBSYSTEMS=="xen", ATTR{capability}=="*",
ACTION=="add", PROGRAM="/ec2disks -A %k", SYMLINK+="%c"

My current process is:

# create the file
/bin/udevadm control --reload
/bin/udevadm settle
/bin/udevadm trigger --subsystem-match=block --action=add


The system is using udev 215
The only rule in /etc/udev/rules.d is my rule. All others should be the
standard rules. The distro is CoreOS.

Log:


Aug 15 23:13:49 i-863204d8 systemd-udevd[629]: PROGRAM '/ec2disks -A
xvda' /etc/udev/rules.d/10-ec2disks.rules:1
Aug 15 23:13:49 i-863204d8 systemd-udevd[630]: starting '/ec2disks
-A xvda'
Aug 15 23:13:49 i-863204d8 systemd-udevd[629]: '/ec2disks -A
xvda'(out) 'disk/ec2/ami disk/ec2/root disk/ec2/vol-05b50706'
Aug 15 23:13:49 i-863204d8 systemd-udevd[629]: '/ec2disks -A xvda'
[630] exit with return code 0
Aug 15 23:13:49 i-863204d8 systemd-udevd[629]: LINK 'disk/ec2/ami'
/etc/udev/rules.d/10-ec2disks.rules:1
Aug 15 23:13:49 i-863204d8 systemd-udevd[629]: LINK 'disk/ec2/root'
/etc/udev/rules.d/10-ec2disks.rules:1
Aug 15 23:13:49 i-863204d8 systemd-udevd[629]: LINK
'disk/ec2/vol-05b50706' /etc/udev/rules.d/10-ec2disks.rules:1
Aug 15 23:13:49 i-863204d8 systemd-udevd[629]: IMPORT 'cdrom_id
--lock-media /dev/xvda' /usr/lib64/udev/rules.d/60-cdrom_id.rules:16
Aug 15 23:13:49 i-863204d8 systemd-udevd[642]: starting 'cdrom_id
--lock-media /dev/xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: 'cdrom_id
--lock-media /dev/xvda'(err) 'unable to open '/dev/xvda''
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: 'cdrom_id
--lock-media /dev/xvda' [642] exit with return code 1
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: probe /dev/xvda raid
offset=0
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: handling device node
'/dev/xvda', devnum=b202:0, mode=0660, uid=0, gid=6
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: preserve permissions
/dev/xvda, 060660, uid=0, gid=6
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: preserve already
existing symlink '/dev/block/202:0' to '../xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: creating link
'/dev/disk/ec2/ami' to '/dev/xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: creating symlink
'/dev/disk/ec2/ami' to '../../xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: creating link
'/dev/disk/ec2/root' to '/dev/xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: creating symlink
'/dev/disk/ec2/root' to '../../xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: creating link
'/dev/disk/ec2/vol-05b50706' to '/dev/xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: creating symlink
'/dev/disk/ec2/vol-05b50706' to '../../xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: created db file
'/run/udev/data/b202:0' for '/devices/vbd-2048/block/xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: adding watch on
'/dev/xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: created db file
'/run/udev/data/b202:0' for '/devices/vbd-2048/block/xvda'
Aug 15 23:14:31 i-863204d8 systemd-udevd[410]: Check if link
configuration needs reloading.
Aug 15 23:14:31 i-863204d8 systemd-udevd[410]: device 0x7f29dc30fc90
has devpath '/devices/vbd-2048/block/xvda'
Aug 15 23:14:31 i-863204d8 systemd-udevd[410]: inotify event: 8 for
/dev/xvda
Aug 15 23:14:31 i-863204d8 systemd-udevd[410]: device 0x7f29dc31f350
has devpath '/devices/vbd-2048/block/xvda'
Aug 15 23:14:31 i-863204d8 systemd-udevd[410]: device /dev/xvda
closed, synthesising 'change'
Aug 15 23:14:31 i-863204d8 systemd-udevd[731]: IMPORT 'cdrom_id
--lock-media /dev/xvda' /usr/lib64/udev/rules.d/60-cdrom_id.rules:16
Aug 15 23:14:31 i-863204d8 systemd-udevd[732]: starting 'cdrom_id
--lock-media /dev/xvda'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: 'cdrom_id
--lock-media /dev/xvda'(err) 'unable to open '/dev/xvda''
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: 'cdrom_id
--lock-media /dev/xvda' [732] exit with return code 1
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: IMPORT builtin
'path_id' /usr/lib64/udev/rules.d/60-persistent-storage.rules:55
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: device 0x7f29dc308070
has devpath '/devices/vbd-2048'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: IMPORT builtin
'path_id' returned non-zero
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: IMPORT builtin
'blkid' /usr/lib64/udev/rules.d/60-persistent-storage.rules:70
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: probe /dev/xvda raid
offset=0
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: no db file to read
/run/udev/data/+xen:vbd-2048: No such file or directory
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: update old name,
'/dev/disk/ec2/ami' no longer belonging to '/devices/vbd-2048/block/xvda'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: no reference left,
remove '/dev/disk/ec2/ami'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: update old name,
'/dev/disk/ec2/root' no longer belonging to '/devices/vbd-2048/block/xvda'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: no reference left,
remove '/dev/disk/ec2/root'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: update old name,
'/dev/disk/ec2/vol-05b50706' no longer belonging to
'/devices/vbd-2048/block/xvda'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: no reference left,
remove '/dev/disk/ec2/vol-05b50706'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: handling device node
'/dev/xvda', devnum=b202:0, mode=0600, uid=0, gid=0
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: preserve already
existing symlink '/dev/block/202:0' to '../xvda'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: created db file
'/run/udev/data/b202:0' for '/devices/vbd-2048/block/xvda'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: adding watch on
'/dev/xvda'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: created db file
'/run/udev/data/b202:0' for '/devices/vbd-2048/block/xvda'



If someone can explain to me why the links are getting removed, I would
appreciate it.

Thanks


-Patrick
--
To unsubscribe from this list: send the line "unsubscribe linux-hotplug" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Patrick Hemmer
2014-08-16 03:07:05 UTC
Permalink
*From:* Patrick Hemmer <***@stormcloud9.net>
*Sent:* 2014-08-15 19:46:21 EDT
*To:* linux-***@vger.kernel.org
*Subject:* device symlinks being removed
Post by Patrick Hemmer
It seems I have some sort of race condition when using udev rules to set
up some device symlinks, but I'm not sure why.
I'm building EC2 boxes, and immediately after they boot, they add some
udev rules to create symlinks, and then call `udevadm trigger` to
process the rules. The problem is that during this procedure, sometimes
some of the links are missing. The udev debug log indicates the links
were created, and then subsequently removed.
The complete system log can be viewed at http://dpaste.com/1BN5FKA
However I've grabbed what look like the interesting lines, and have
included them at the bottom. Notice the ones such as
creating symlink '/dev/disk/ec2/vol-05b50706' to '../../xvda'
and
update old name, '/dev/disk/ec2/vol-05b50706' no longer belonging to
'/devices/vbd-2048/block/xvda'
no reference left, remove '/dev/disk/ec2/vol-05b50706'
SUBSYSTEM=="block", SUBSYSTEMS=="xen", ATTR{capability}=="*",
ACTION=="add", PROGRAM="/ec2disks -A %k", SYMLINK+="%c"
# create the file
/bin/udevadm control --reload
/bin/udevadm settle
/bin/udevadm trigger --subsystem-match=block --action=add
The system is using udev 215
The only rule in /etc/udev/rules.d is my rule. All others should be the
standard rules. The distro is CoreOS.
Aug 15 23:13:49 i-863204d8 systemd-udevd[629]: PROGRAM '/ec2disks -A
xvda' /etc/udev/rules.d/10-ec2disks.rules:1
Aug 15 23:13:49 i-863204d8 systemd-udevd[630]: starting '/ec2disks
-A xvda'
Aug 15 23:13:49 i-863204d8 systemd-udevd[629]: '/ec2disks -A
xvda'(out) 'disk/ec2/ami disk/ec2/root disk/ec2/vol-05b50706'
Aug 15 23:13:49 i-863204d8 systemd-udevd[629]: '/ec2disks -A xvda'
[630] exit with return code 0
Aug 15 23:13:49 i-863204d8 systemd-udevd[629]: LINK 'disk/ec2/ami'
/etc/udev/rules.d/10-ec2disks.rules:1
Aug 15 23:13:49 i-863204d8 systemd-udevd[629]: LINK 'disk/ec2/root'
/etc/udev/rules.d/10-ec2disks.rules:1
Aug 15 23:13:49 i-863204d8 systemd-udevd[629]: LINK
'disk/ec2/vol-05b50706' /etc/udev/rules.d/10-ec2disks.rules:1
Aug 15 23:13:49 i-863204d8 systemd-udevd[629]: IMPORT 'cdrom_id
--lock-media /dev/xvda' /usr/lib64/udev/rules.d/60-cdrom_id.rules:16
Aug 15 23:13:49 i-863204d8 systemd-udevd[642]: starting 'cdrom_id
--lock-media /dev/xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: 'cdrom_id
--lock-media /dev/xvda'(err) 'unable to open '/dev/xvda''
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: 'cdrom_id
--lock-media /dev/xvda' [642] exit with return code 1
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: probe /dev/xvda raid
offset=0
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: handling device node
'/dev/xvda', devnum=b202:0, mode=0660, uid=0, gid=6
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: preserve permissions
/dev/xvda, 060660, uid=0, gid=6
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: preserve already
existing symlink '/dev/block/202:0' to '../xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: creating link
'/dev/disk/ec2/ami' to '/dev/xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: creating symlink
'/dev/disk/ec2/ami' to '../../xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: creating link
'/dev/disk/ec2/root' to '/dev/xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: creating symlink
'/dev/disk/ec2/root' to '../../xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: creating link
'/dev/disk/ec2/vol-05b50706' to '/dev/xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: creating symlink
'/dev/disk/ec2/vol-05b50706' to '../../xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: created db file
'/run/udev/data/b202:0' for '/devices/vbd-2048/block/xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: adding watch on
'/dev/xvda'
Aug 15 23:13:52 i-863204d8 systemd-udevd[629]: created db file
'/run/udev/data/b202:0' for '/devices/vbd-2048/block/xvda'
Aug 15 23:14:31 i-863204d8 systemd-udevd[410]: Check if link
configuration needs reloading.
Aug 15 23:14:31 i-863204d8 systemd-udevd[410]: device 0x7f29dc30fc90
has devpath '/devices/vbd-2048/block/xvda'
Aug 15 23:14:31 i-863204d8 systemd-udevd[410]: inotify event: 8 for
/dev/xvda
Aug 15 23:14:31 i-863204d8 systemd-udevd[410]: device 0x7f29dc31f350
has devpath '/devices/vbd-2048/block/xvda'
Aug 15 23:14:31 i-863204d8 systemd-udevd[410]: device /dev/xvda
closed, synthesising 'change'
Aug 15 23:14:31 i-863204d8 systemd-udevd[731]: IMPORT 'cdrom_id
--lock-media /dev/xvda' /usr/lib64/udev/rules.d/60-cdrom_id.rules:16
Aug 15 23:14:31 i-863204d8 systemd-udevd[732]: starting 'cdrom_id
--lock-media /dev/xvda'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: 'cdrom_id
--lock-media /dev/xvda'(err) 'unable to open '/dev/xvda''
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: 'cdrom_id
--lock-media /dev/xvda' [732] exit with return code 1
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: IMPORT builtin
'path_id' /usr/lib64/udev/rules.d/60-persistent-storage.rules:55
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: device 0x7f29dc308070
has devpath '/devices/vbd-2048'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: IMPORT builtin
'path_id' returned non-zero
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: IMPORT builtin
'blkid' /usr/lib64/udev/rules.d/60-persistent-storage.rules:70
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: probe /dev/xvda raid
offset=0
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: no db file to read
/run/udev/data/+xen:vbd-2048: No such file or directory
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: update old name,
'/dev/disk/ec2/ami' no longer belonging to '/devices/vbd-2048/block/xvda'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: no reference left,
remove '/dev/disk/ec2/ami'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: update old name,
'/dev/disk/ec2/root' no longer belonging to '/devices/vbd-2048/block/xvda'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: no reference left,
remove '/dev/disk/ec2/root'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: update old name,
'/dev/disk/ec2/vol-05b50706' no longer belonging to
'/devices/vbd-2048/block/xvda'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: no reference left,
remove '/dev/disk/ec2/vol-05b50706'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: handling device node
'/dev/xvda', devnum=b202:0, mode=0600, uid=0, gid=0
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: preserve already
existing symlink '/dev/block/202:0' to '../xvda'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: created db file
'/run/udev/data/b202:0' for '/devices/vbd-2048/block/xvda'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: adding watch on
'/dev/xvda'
Aug 15 23:14:34 i-863204d8 systemd-udevd[731]: created db file
'/run/udev/data/b202:0' for '/devices/vbd-2048/block/xvda'
If someone can explain to me why the links are getting removed, I would
appreciate it.
Thanks
-Patrick
Finally figured out it. For some reason, another event was sometimes
being triggered on the device. My udev rule was matching only 'add'
events, and this other event was apparently something else. So my rule
wouldn't match, and the device would lose the symlinks.

Just removed the ACTION=="add" from the udev rule and all appears well.

-Patrick

--
To unsubscribe from this list: send the line "unsubscribe linux-hotplug" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Zbigniew Jędrzejewski-Szmek
2014-08-18 14:42:29 UTC
Permalink
Post by Patrick Hemmer
Post by Patrick Hemmer
SUBSYSTEM=="block", SUBSYSTEMS=="xen", ATTR{capability}=="*",
ACTION=="add", PROGRAM="/ec2disks -A %k", SYMLINK+="%c"
Finally figured out it. For some reason, another event was sometimes
being triggered on the device. My udev rule was matching only 'add'
events, and this other event was apparently something else. So my rule
wouldn't match, and the device would lose the symlinks.
Just removed the ACTION=="add" from the udev rule and all appears well.
Yep. For a similar case see http://cgit.freedesktop.org/systemd/systemd/commit/?id=e0d856dd48.

Zbyszek
--
To unsubscribe from this list: send the line "unsubscribe linux-hotplug" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Loading...