More on hotplug issue w/HAL

[Matthew Mastracci]

I'm learning a lot by taking a look inside the guts of hald.  :)

I've taken a look and it seems as if my removable drive is also having
trouble being picked up by hal when hotplugged.  The SCSI host and
interface devices appear, but no disk appears beneath.  When starting
hald, the probing correctly picks up this disk.  

Note that I've added an extra HAL_INFO call before a few
ds_device_async_find_by_key_value_string calls, and in some
*_got_parent() methods to determine what it was actually looking for:

[I] device_info.c:183 handle_match() : Checking that key='usb.vendor_id'
is a int that equals 1193
[I] linux/linux_osspec.c:400 handle_hotplug() : HotplugEvent add,
subsystem=scsi_host
[I] linux/linux_osspec.c:457 handle_hotplug() : Adding classdevice @
sysfspath /initrd/sys/class/scsi_host/host20
[I] linux/linux_osspec.c:400 handle_hotplug() : HotplugEvent add,
subsystem=scsi
[I] linux/linux_osspec.c:400 handle_hotplug() : HotplugEvent add,
subsystem=block
[I] linux/linux_osspec.c:457 handle_hotplug() : Adding classdevice @
sysfspath /initrd/sys/block/sdf
[I] linux/linux_class_block.c:190 visit_class_device_block() : For path
= /initrd/sys/block/sdf, looking for parent_sysfs_path =
/initrd/sys/devices/pci0000:00/0000:00:02.0/usb2/2-1/2-1.1/2-1.1:1.0/host20/20:0:0:0
[I] linux/linux_osspec.c:400 handle_hotplug() : HotplugEvent add,
subsystem=block
[I] linux/linux_osspec.c:457 handle_hotplug() : Adding classdevice @
sysfspath /initrd/sys/block/sdf/sdf1
[I] linux/linux_class_block.c:190 visit_class_device_block() : For path
= /initrd/sys/block/sdf/sdf1, looking for parent_sysfs_path =
/initrd/sys/block/sdf
[I] linux/linux_osspec.c:400 handle_hotplug() : HotplugEvent add,
subsystem=scsi_device
[I] linux/linux_osspec.c:457 handle_hotplug() : Adding classdevice @
sysfspath /initrd/sys/class/scsi_device/20:0:0:0
[I] linux/linux_class_scsi.c:267 visit_class_device_scsi_device() : For
path = /initrd/sys/class/scsi_device/20:0:0:0, looking for
parent_sysfs_path =
/initrd/sys/devices/pci0000:00/0000:00:02.0/usb2/2-1/2-1.1/2-1.1:1.0/host20
[I] linux/linux_osspec.c:400 handle_hotplug() : HotplugEvent add,
subsystem=usb
[I] linux/linux_osspec.c:409 handle_hotplug() : Adding device @
sysfspath
/initrd/sys/devices/pci0000:00/0000:00:02.0/usb2/2-1/2-1.1/2-1.1:1.0
[I] linux/linux_usb.c:877 visit_device_usb() : usb device @
/initrd/sys/devices/pci0000:00/0000:00:02.0/usb2/2-1/2-1.1/2-1.1:1.0 is
an interface
[I] device_info.c:648 scan_fdi_files() : scan_fdi_files: Processing file
'canon-digital-ixus-v.fdi'
[I] linux/linux_class_scsi.c:192
visit_class_device_scsi_host_got_parent() : data2=0x00000000,
d=0x095385d0, d->udi=/org/freedesktop/Hal/devices/temp/81,
parent->udi=/org/freedesktop/Hal/devices/usbif_usb_5dc_80_1_-1_L331211418100315AA  0000000000000000000000000_0, parent->in_gdl=1, d->
[I] device_info.c:648 scan_fdi_files() : scan_fdi_files: Processing file
'canon-digital-ixus-v.fdi'
[I] linux/linux_class_scsi.c:293
visit_class_device_scsi_device_got_parent() : data2=0x00000000,
d=0x0952df48, d->udi=/org/freedesktop/Hal/devices/temp/84,
parent->udi=/org/freedesktop/Hal/devices/scsi_host_usbif_usb_5dc_80_1_-1_L331211418100315AA  0000000000000000000000000_0, parent->in_gdl=1, d->
[I] device_info.c:648 scan_fdi_files() : scan_fdi_files: Processing file
'canon-digital-ixus-v.fdi'
[I] linux/linux_class_block.c:220 visit_class_device_block_got_parent()
: data2=0x00000000, d=0x0950f310,
d->udi=/org/freedesktop/Hal/devices/temp/82,
parent->udi=/org/freedesktop/Hal/devices/scsi_device_scsi_host_usbif_usb_5dc_80_1_-1_L331211418100315AA  0000000000000000000000000_0, parent->in_gdl=1
[I] linux/linux_class_block.c:612 etc_mtab_process_all_block_devices() :
/etc/mtab changed, processing all block devices
[I] linux/linux_class_block.c:640 etc_mtab_process_all_block_devices() :
/dev/hda5 mounted at /, major:minor=3:5, fstype=ext3,
udi=/org/freedesktop/Hal/devices/block_3_5
[I] linux/linux_class_block.c:640 etc_mtab_process_all_block_devices() :
/dev/hda1 mounted at /boot, major:minor=3:1, fstype=ext2,
udi=/org/freedesktop/Hal/devices/block_3_1
[I] linux/linux_class_block.c:640 etc_mtab_process_all_block_devices() :
/dev/hde5 mounted at /mnt/ext, major:minor=33:5, fstype=ext3,
udi=/org/freedesktop/Hal/devices/block_33_5

and then, 30 seconds after plugin:

[I] linux/linux_class_block.c:220 visit_class_device_block_got_parent()
: data2=0x00000000, d=0x091474a0,
d->udi=/org/freedesktop/Hal/devices/temp/95, parent->udi=no parent,
parent->in_gdl=42
[W] linux/linux_class_block.c:224 visit_class_device_block_got_parent()
: No parent for block device!

So, it seems like it can't find the parent for /initrd/sys/block/sdf, so
it can't add sdf itself.  

I have noticed that there is a SCSI interface device underneath the USB
drive's node with a path of:

/initrd/sys/devices/pci0000:00/0000:00:02.0/usb2/2-1/2-1.1/2-1.1:1.0/host20/20:0:0:0

The log line above (For xxx, parent = xxx) shows that we're looking for
this node:

/initrd/sys/devices/pci0000:00/0000:00:02.0/usb2/2-1/2-1.1/2-1.1:1.0/host20/20:0:0:0

They match, but the node doesn't seem to get found.

I thought it was a race condition, but I can clearly see the SCSI
device/host getting added before the block device.  It's just that the
block device ends up getting no parent!

This device is definitely hotplugged:

[root at matt root]# cat /tmp/hal.txt | grep "DEVPATH"

DEVPATH=/devices/pci0000:00/0000:00:02.0/usb2/2-1/2-1.1
DEVPATH=/class/scsi_host/host20
DEVPATH=/devices/pci0000:00/0000:00:02.0/usb2/2-1/2-1.1/2-1.1:1.0/host20/20:0:0:0
DEVPATH=/block/sdf
DEVPATH=/block/sdf/sdf1
DEVPATH=/class/scsi_device/20:0:0:0
DEVPATH=/devices/pci0000:00/0000:00:02.0/usb2/2-1/2-1.1/2-1.1:1.0

-- 
Matthew Mastracci <matt at aclaro.com>