FAQ Search Today's Posts Mark Forums Read
» Video Reviews

» Linux Archive

Linux-archive is a website aiming to archive linux email lists and to make them easily accessible for linux users/developers.


» Sponsor

» Partners

» Sponsor

Go Back   Linux Archive > ArchLinux > ArchLinux General Discussion

 
 
LinkBack Thread Tools
 
Old 06-20-2012, 05:42 PM
Arno Gaboury
 
Default What causes the 3-5 sec delay befo: running early hooks (udev)?

On 06/20/2012 07:21 PM, David C. Rankin wrote:

Guys,

After recent updates to 3.4.3 and systemd-tools, etc., I have a new
delay on boot. The system just seems to sit for any extra 5 secs or so
with a blank screen after switching from grub to start booting. The
delay happens before the first line:


:: running early hooks (udev)

is written to the screen. Does anybody know what is causing this?
initramfs decompression? New systemd-tools udev stuff? After updating
3-4 boxes, this delay period is notable. Just curious whether this can
be tweaked or eliminated. Thanks for any info.



I can observe same on my box.
 
Old 06-20-2012, 06:10 PM
Tom Gundersen
 
Default What causes the 3-5 sec delay befo: running early hooks (udev)?

On Jun 20, 2012 7:21 PM, "David C. Rankin" <drankinatty@suddenlinkmail.com>
wrote:
>
> Guys,
>
> After recent updates to 3.4.3 and systemd-tools, etc., I have a new
delay on boot. The system just seems to sit for any extra 5 secs or so with
a blank screen after switching from grub to start booting. The delay
happens before the first line:
>
> :: running early hooks (udev)

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

> is written to the screen. Does anybody know what is causing this?
initramfs decompression? New systemd-tools udev stuff? After updating 3-4
boxes, this delay period is notable. Just curious whether this can be
tweaked or eliminated. Thanks for any info.
>
> --
> David C. Rankin, J.D.,P.E.
>
 
Old 06-20-2012, 07:44 PM
"David C. Rankin"
 
Default What causes the 3-5 sec delay befo: running early hooks (udev)?

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=nonew ns=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.
 
Old 06-20-2012, 08:11 PM
Leonid Isaev
 
Default What causes the 3-5 sec delay befo: running early hooks (udev)?

On Wed, 20 Jun 2012 14:44:53 -0500
"David C. Rankin" <drankinatty@suddenlinkmail.com> wrote:

> 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

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.

>
> [ 13.895401] vgaarb: device changed decodes:
> PCI:0000:01:00.0,olddecodes=io+mem,decodes=nonew ns=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)'?
>

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

--
Leonid Isaev
GnuPG key: 0x164B5A6D
Fingerprint: C0DF 20D0 C075 C3F1 E1BE 775A A7AE F6CB 164B 5A6D
 
Old 06-20-2012, 08:38 PM
"David C. Rankin"
 
Default What causes the 3-5 sec delay befo: running early hooks (udev)?

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.
 

Thread Tools




All times are GMT. The time now is 01:31 AM.

VBulletin, Copyright ©2000 - 2014, Jelsoft Enterprises Ltd.
Content Relevant URLs by vBSEO ©2007, Crawlability, Inc.
Copyright 2007 - 2008, www.linux-archive.org