HAL needs the hotplug SEQNUM from the dev.d/ events

Sun Aug 29 08:39:23 PDT 2004

On Thu, 2004-08-26 at 02:37 +0200, Kay Sievers wrote:
> Hey David,
> here we go with the SEQNUM passed through:
>   udevsend -> udevd -> udev -> dev.d/ -> hal.dev -> hald.
> 
> Attached are the patches for udev (I will send it upstream if this
> renders useful) and for hal_dev.c and linux/osspec.c to use it.
> 
> 02:23:46.815 [I] linux/osspec.c:1148: entering add, subsystem=input devpath=/class/input/mouse2 devnode=/udev/input/mouse2 seqnum=392
> 02:23:46.816 [I] linux/osspec.c:973: dev_file=/udev/input/mouse2 is for udi=/org/freedesktop/Hal/devices/temp/68
> 02:23:46.816 [I] linux/osspec.c:979: .udev.class_name = input
> 02:23:46.824 [I] linux/class_device.c:498: Merged udi=/org/freedesktop/Hal/devices/temp/68 onto /org/freedesktop/Hal/devices/usb_usb_device_46d_c03e_2000_-1_noserial_0
> 02:23:46.959 [I] linux/osspec.c:1148: entering add, subsystem=input devpath=/class/input/event3 devnode=/udev/input/event3 seqnum=393
> 

Hey Kay,

Thanks a lot for this. I was unable to properly test; the patch does
apply and it works, but it kind of renders my system unstable insofar
that Fedora uses udev in the initrd and booting was a problem. I'm sure
this was my own fault though :-).

However, I think you should send the patch upstream anyway. It would
also be perfect if you could ask Greg for somewhere to retrieve the last
SEQNUM seen; we'll need this in hal and I'm sure you can use it in udevd
as well! Perhaps something like /proc/sys/kernel/hotplug_last_seqnum or
something? Oh well.

Here's why we need the SEQNUM (and my late reply is partly because it
took some time to prepare this); well, first of all 

 http://www.kernel.org/pub/linux/utils/kernel/hotplug/RFC-dev.d

states that we'll should get it; second, consider this USB hub with
devices (yeah, I had to split it onto two h-d-m views :-)

 http://freedesktop.org/~david/hal-many-usb-devices.png

This basically works with HAL as is but only because we got a timeout of
about 60 seconds. If I crank down the timeout to 20 seconds on my old
Dell Inspiron P3 650MHz with 192MB RAM, then it stops working. See

 http://freedesktop.org/~david/hal-many-usb-devices.txt

for the debug output. Notably, the following snippets are interesting
(in chronological order)

        16:57:39.067 [W] linux/osspec.c:1358: First SEQNUM=456; sleeping 2500ms to get a few more events
        16:57:39.079 [I] linux/osspec.c:1235: ******************************************
        16:57:39.080 [I] linux/osspec.c:1236: **** hotplug_counter is now 1
        16:57:39.080 [I] linux/osspec.c:1237: ******************************************
        16:57:39.080 [I] linux/osspec.c:1381: Queing up seqnum=456, sysfspath=/devices/pci0000:00/0000:00:07.2/usb1/1-1, subsys=usb

This is when I hotplug the hub (nasty 2500ms sleep on first SEQNUM;
getting the last SEQNUM will solve this)

        16:57:49.547 [I] linux/osspec.c:1381: Queing up seqnum=483, sysfspath=/block/sdb, subsys=block

Here we get the hotplug event for /block/sdb

        16:57:53.491 [I] linux/osspec.c:1171: entering add, Seqnum=-1  subsystem=block devpath=/block/sdb devnode=/dev/sdb

This is the device node created and named by udev

        16:58:03.137 [I] linux/osspec.c:1381: Queing up seqnum=514, sysfspath=/devices/pci0000:00/0000:00:07.2/usb1/1-1/1-1.4/1-1.4.3/1-1.4.3:1.0/host11/11:0:0:0, subsys=scsi

This is the last hotplug event sent (lots of activity prior the that by
usb-agent shell script cranking the load up to 4-5 on my box)

        16:58:13.491 [W] linux/osspec.c:1008: No HAL device corresponding to device file /dev/sdb

Here we time out searching for a hal device to associate with /dev/sdb

        16:58:14.052 [I] linux/osspec.c:1125: add, SEQNUM=483 subsystem=block sysfs_path=/sys/block/sdb

Heh, only half a second late, but to late we decide to process the
hotplug event for /block/sdb

        16:58:34.060 [W] linux/class_device.c:399: Never got device file for class device at /sys/block/sdb

We timeout twenty seconds later. Note that all hotplug processing is
blocked in this interval. So this is really fucking bad. Hence, why the
timeout is 60 seconds, but still it sucks.

Btw, with the timeout set to 60 seconds (which is what it is now), the
right things happen, see

 http://freedesktop.org/~david/hal-many-usb-devices-correct.txt

for details; this is, for instance, my fstab

        LABEL=/                 /                       ext3    defaults        1 1
        /dev/hda2               swap                    swap    defaults        0 0
        none                    /dev/pts                devpts  gid=5,mode=620  0 0
        none                    /dev/shm                tmpfs   defaults        0 0
        none                    /proc                   proc    defaults        0 0
        none                    /sys                    sysfs   defaults        0 0
        /dev/hdd                /media/dvdrom           auto    noauto,user,exec,kudzu,ro 0 0
        /dev/hdc                /media/floppy           auto    noauto,user,exec,kudzu 0 0
        /dev/sda1               /media/usbdisk          vfat    noauto,user,exec,kudzu 0 0
        /dev/sda2               /media/usbdisk1         hfsplus noauto,user,exec,kudzu,noatime,sync 0 0
        /dev/sr0                /media/cdrw_dvdrw       auto    noauto,user,exec,kudzu,ro 0 0
        /dev/sdb1               /media/compact_flash    vfat    noauto,user,exec,kudzu,noatime,sync 0 0
        /dev/sdc                /media/floppy1          auto    noauto,user,exec,kudzu 0 0
        /dev/sdd                /media/compact_flash1   vfat    noauto,user,exec,kudzu,noatime,sync 0 0
        /dev/sdg1               /media/sd_mmc           vfat    noauto,user,exec,kudzu,noatime,sync 0 0
        /dev/sdh1               /media/usbdisk2         vfat    noauto,user,exec,kudzu,noatime,sync 0 0
        /dev/sdh5               /media/usbdisk3         vfat    noauto,user,exec,kudzu,noatime,sync 0 0

(Note: The hotplug of the hub occurred at 17:29:40, the last event from
the kernel was at 17:30:06 and hald was finished processing at
17:30:25.. This is a long time; I partly blame the hotplug scripts (go
take a look at them :-) but there is room for improvement in hal as well
(callouts etc.). Will do some more benchmarking and profiling when time
permits. Remember, this is an old crappy laptop and it sure is a lot of
devices. Patches are welcome ;-) as always)

So.. Having the SEQNUM from the udev event will fix this; we only then
use a timeout for waiting for udev to name the device, but udev will
(almost always) be faster than hald! Having the last_seqnum will
eliminate the 2500ms sleep on the first hotplug event.

Cheers,
David
_______________________________________________
hal mailing list
hal at freedesktop.org
http://freedesktop.org/mailman/listinfo/hal