On 06/20/2012 01:10 PM, Tom Gundersen wrote:

It is either the kernel or the initramfs. Your dmesg might tell you more (possibly some misbehaving kernel module?). Also, what modules/hooks do you have in your initramfs?

Tom

Thanks Arno, Tom, There are no non-default hooks on the desktops. They all have: HOOKS="base udev autodetect pata scsi sata filesystems usbinput fsck" On my 2 server boxes, I have dmraid in this order: MODULES="dm_mod dm_mirror" HOOKS="base udev autodetect pata scsi sata dmraid filesystems usbinput fsck" I do note that fsck was added at some point in time, but that was a default and not something I added. Looking at dmesg, I see the following delays > 2 sec: [ 7.957888] EXT4-fs (sdc5): mounting ext3 file system using the ext4 subsystem [ 8.016583] EXT4-fs (sdc5): mounted filesystem with ordered data mode. Opts: (null) [ 10.236553] udevd[140]: starting version 185 [ 13.895401] vgaarb: device changed decodes: PCI:0000:01:00.0,olddecodes=io+mem,decodes=none:owns=io+mem [ 13.942931] NVRM: loading NVIDIA UNIX x86 Kernel Module 302.17 Tue Jun 12 18:37:51 PDT 2012 [ 31.985912] EXT4-fs (sdc5): re-mounted. Opts: (null) [ 32.049154] EXT4-fs (sdc7): mounted filesystem with ordered data mode. Opts: (null) There is 19 sec for NVIDIA. [ 35.656087] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready [ 46.656677] eth0: no IPv6 routers present 11 secs for network init. [ 46.656677] eth0: no IPv6 routers present [ 144.443911] vboxdrv: Found 2 processor cores. 98 sec courtesy of dkms and a new kernel. I don't know, but the delay I see before the ':: running early hooks (udev)' message does not seem to correlate to these entries in dmesg. Is dmesg logging even active before the ':: running early hooks (udev)'? -- David C. Rankin, J.D.,P.E.

On 06/20/2012 03:11 PM, Leonid Isaev wrote:

No, you need logs much before that. Udev should be noted twice in dmesg: one is when initramfs is unpacked (with low PID ~ 40); and you posted another.

Thanks Leonid, I found the earlier entry, but there is virtually no delay on the earlier udev start: [ 1.412277] Write protecting the kernel read-only data: 1120k [ 1.426225] udevd[40]: starting version 185 [ 1.494146] usbcore: registered new interface driver usbfs [ 1.494798] usbcore: registered new interface driver hub [ 1.501646] SCSI subsystem initialized full dmesg at: http://nirvana.3111skyline.com/dl/arch/bugs/dmesg0620.txt <snip>

Yes, everything is in dmesg.log and kernel.log (unless you have reconfigured syslog).

The only other brief delays in dmesg that might be it are: [ 4.057038] usbhid: USB HID core driver [ 6.302103] sd 0:0:0:0: [sda] 586114704 512-byte logical blocks: (300 GB/279 GiB) [ 6.993289] sr 0:0:1:0: Attached scsi CD-ROM sr0 [ 7.957888] EXT4-fs (sdc5): mounting ext3 file system using the ext4 subsystem [ 8.016583] EXT4-fs (sdc5): mounted filesystem with ordered data mode. Opts: (null) [ 10.236553] udevd[140]: starting version 185 [ 11.189242] input: Power Button as /devices/LNXSYSTM:00/device:00/PNP0C0C:00/input/input3 This group of messages taken together is just about 6-7 seconds that would correspond to the delay. Is there a way I could figure out where in this period of time the boot message of ':: running early hooks (udev)' is displayed? My _guess_ is the delay is the 4.057038 -> 10.236553 time period, then the ':: running early hooks (udev)' message pops up. If that is the case, then it just looks like the 2.3 secs for usbhid + 3.9 secs for sda,sdc initialization is the cause of the delay. Anything in the 3.9 sec drive initialization look strange? -- David C. Rankin, J.D.,P.E.