[2.6.32-11 regression] 5 second delay on early boot during usb_id

I had a first quick look at this, and it doesn't reproduce with udevadm trigger in the booted system, and not even with init=/bin/bash and starting udev/udevadm trigger manually.

Confirmed with 2.6.32-12:

http://people.canonical.com/~pitti/bootcharts/daniel-lucid-20100128-1-2.6.32-12.png

I took a look at the three udev rules in the initramfs that use usb_id:

 * We do not need the hplip permission one from 50-udev-default.rules at all; it will be caught by the udevadm trigger in the real system

 * I am pretty sure that we do not need a /dev/disks/by-id/ symlink in the initramfs. We only support UUIDs for file systems, which are generated by blkid, not usb_id.

Thus I jsut removed copying usb_id into the initramfs by commenting out the line in /usr/share/initramfs-tools/hooks/udev. This might be worth doing either way, since it speeds up the time spent in initramfs?

When I do that, I do not get the early 5 s khubd/usb_id blocking any more, and the total boot time again drops from 20 to 15 seconds (just with kernel 2.6.32-10). Instead, I now get a 2.5 s usb_id process hanging off the /etc/init/udevtrigger.conf tree, presumably on the same problematic device. However, it does not slow down the boot any more.

http://people.canonical.com/~pitti/bootcharts/daniel-lucid-20100201-no-initramfs-usb_id.png is the associated bootchart with dropping usb_id from initramfs.

Discussed with Scott, and we do support booting with by-id symlinks, thus we need to keep usb_id in the initramfs.

Ok, I have just discovered that this usb-id is much much quicker, of the order of 0.2s if there is an MMC card in the slot on the machine (Dell mini 10v). Remove it and its back to 5s.

Ok I have isolated this to new locking in the sysfs file read code. This seems to be necessary locking as there was a chance that the values being read could be freed underneath us. Contention between usb_id and khubd (presumably) scanning the hub leads to extended waits usb_id trying to aquire the usb device semaphore. We could probabally fix this by converting the update of these values to rcu but that would require fixing all of those sharing the sysfs code, which appears to be all usb devices.

So the key question is, Is the delay on usb_id actually causing an issue here now that we are not blocking on it?

> So the key question is, Is the delay on usb_id actually causing an issue here now that we are not blocking on it?

The extra I/O wait/process blocking/etc now costs us .3 seconds (averaged over three reboots, between lucid current and lucid current userspace with -10 kernel, and looked at time until when gdm starts).

So it's certainly small enough to not warrant rewriting the entire subsytem :-)

As discussed on IRC, there are many instances where we *will* block on it - there's still a udevadm settle in the boot, it's just later than usual.

This will add 5s to the boot of any non-KMS machine, any machine with encrypted disks, etc.

While that's not our "reference image", it's an important enough set of users that this does need to be fixed

Ok testing seems to indicate that there is a .3s general benefit for fixing this for the reference platform. There is also a high probabality of a multi second delay for a large userbase so this seems worth fixing. Testing of some RCU patches is in progress.

This bug was fixed in the package linux - 2.6.32-14.20

---------------
linux (2.6.32-14.20) lucid; urgency=low

  [ Andy Whitcroft ]

  * rebuild following the GCC update to match compiler for out of tree modules
  * Revert "[Config] drbd -- enable"
  * Revert "ubuntu: drbd -- version 8.3.1"
  * SAUCE: khubd -- switch USB product/manufacturer/serial handling to RCU
    - LP: #510937
 -- Andy Whitcroft <email address hidden> Fri, 19 Feb 2010 18:47:18 +0000