Bug 12311

Summary:	Long delays during boot process
Product:	Other	Reporter:	Kevin Shanahan (kmshanah)
Component:	Other	Assignee:	other_other
Status:	RESOLVED CODE_FIX
Severity:	normal	CC:	akpm, odinoxp
Priority:	P1
Hardware:	All
OS:	Linux
Kernel Version:	2.6.28	Subsystem:
Regression:	No	Bisected commit-id:
Attachments:	Kernel config used for 2.6.28 syslog from boot of 2.6.28

Description Kevin Shanahan 2008-12-27 20:39:28 UTC

Latest working kernel version: 2.6.24-1-686 (distro kernel)
Earliest failing kernel version: 2.6.25-1-686 (distro kernel)
Distribution: Debian Unstable/Sid
Hardware Environment: Dell Latitude D420 Laptop (Core Duo, 1.5GB RAM)
Software Environment: Debian Unstable/Sid

Problem Description:

Since Debian updated to kernel version 2.6.25 I have been experiencing long (5s, 10s, 30s) delays in the boot process. For a long time I kept booting the 2.6.24 distro kernel to avoid the problem. The problem continued with Debian's 2.6.26 distro kernel, so I decided to try upstream 2.6.28 kernel as well. This has the same problem.

Steps to reproduce:

Boot any kernel >= 2.6.25 on a (my?) Dell Latitude D420 laptop

e.g. there seems to be a 4 second delay where nothing else happens before the usb-mass storage scan completes:

[    4.004967] hub 2-2.3:1.0: USB hub found
[    4.006877] hub 2-2.3:1.0: 3 ports detected
[    4.012076] usb 2-2.3: New USB device found, idVendor=0b97, idProduct=7761
[    4.012153] usb 2-2.3: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    4.285965] usb 2-2.3.2: new full speed USB device using uhci_hcd and address 4
[    4.401140] usb 2-2.3.2: configuration #1 chosen from 1 choice
[    4.404341] usb 2-2.3.2: New USB device found, idVendor=0b97, idProduct=7762
[    4.404423] usb 2-2.3.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    4.404515] usb 2-2.3.2: Product: O2Micro CCID SC Reader
[    4.404584] usb 2-2.3.2: Manufacturer: O2
[    8.308340] usb-storage: device scan complete

Then, shortly after there is huge (38s?) delay before filesystems get mounted.

[    8.311116] scsi 2:0:0:0: CD-ROM            HL-DT-ST DVD+-RW GWA4083N B105 PQ: 0 ANSI: 0
[    8.324642] sr0: scsi3-mmc drive: 24x/24x writer cd/rw xa/form2 cdda tray
[    8.324721] Uniform CD-ROM driver Revision: 3.20
[    8.324972] sr 2:0:0:0: Attached scsi CD-ROM sr0
[    8.325125] sr 2:0:0:0: Attached scsi generic sg1 type 5
[   46.153440] PM: Starting manual resume from disk
[   46.189837] kjournald starting.  Commit interval 5 seconds
[   46.189927] EXT3-fs: mounted filesystem with ordered data mode.
[   49.372377] udevd version 125 started

I'll attach the full syslog from a boot of 2.6.28, with CONFIG_USB_STORAGE_DEBUG enabled and me hitting alt-sysrq-t during the delay periods. Hopefully that contains some clue as to what everything is waiting on.

Comment 1 Kevin Shanahan 2008-12-27 20:41:59 UTC

Created attachment 19503 [details]
Kernel config used for 2.6.28

Comment 2 Kevin Shanahan 2008-12-27 20:47:05 UTC

Created attachment 19504 [details]
syslog from boot of 2.6.28

Here is the syslog extract from a full boot of 2.6.28. Note the delays at 4.404584s and 8.349727s. I hit alt-sysrq-t during both these delays, hoping that something useful would show up. There is another ~30s delay at 52.761617s, but I didn't get the sysrq output for that one this time.

Comment 3 Andrew Morton 2008-12-27 21:12:22 UTC

hm, init is waiting for some process, but which?  Perhaps something
udev-related.

That sysrq output is useful.

Comment 4 Kevin Shanahan 2009-03-30 22:16:59 UTC

Some recent update to Debian userspace seems to have fixed this. Unfortunately I can't point to exactly what, except to say boot times are back to normal now with a kernel.org 2.6.28 or 2.6.29 kernel and current Debian (Sid/unstable) userspace.