udev timeout, slow boot

beretta · 2009-01-21 21:48:20

Recently I upgraded my system (which I believe included the newer kernel, possibly a udev upgrade?) and now on boot, it halts at the line

:: Processing UDev uevents

and waits for over 2 minutes. I can catch a glimpse of a "timeout after 180 seconds" message as it flashes past when it starts moving again, then lose it quickly as everything else boots very quickly. I've also noticed a message when it starts of ALSA about a failure to recognize the sound card and using a "best guess".

Does anyone know off hand which modules should no longer be included with the new kernel? Here's whats in my line in rc.conf:

MOD_AUTOLOAD="yes"
MODULES=(e1000e slhc rt2x00usb rt73usb snd-mixer-oss  snd-pcm-oss 
snd-hwdep snd-page-alloc snd-pcm snd-timer snd snd-hda-intel soundcore usblp)

EDIT:

Here are the actual messages on boot (I rebooted with !slim in rc.conf):

:: Loading UDev uevents
devadm settle timeout of 180 seconds reached, the event queue contains:
   '/sys/module/snd_pcsp'  [1097]
   '/sys/class/scsi_generic/sg0'  [1080]
   '/sys/devices/pci0000:00/0000:00:1c.1/0000:03:00.0/host0/target0:0:0/0:0:0:0'
[1012]
   > UDev uevent processing time:  180216 ms

...
...

::Restoring ALSA Levels
Unknown hardware: "HDA-Intel" "SigmaTel STAC9271D" "HDA:83847627, 80863001, 001002
01" "0x8086" "0x3001"
Hardware is initialized using a guess method                               [FAIL]

Last edited by beretta (2009-01-21 22:02:51)

beretta · 2009-01-21 22:10:05

More clues, this time from /var/log/errors.log:

Jan 21 09:28:20 orion pci 0000:01:00.0: BAR 6: can't allocate mem resource [0xe0000000-0xdfffffff]
Jan 21 09:28:20 orion Error: Driver 'pcspkr' is already registered, aborting...

Adding MODULES=(... !snd_pcsp !pcspkr) does nothing.

EDIT: removed the lines with "Buffer I/O error on device sr0"-- turns out they were because I had left an audio cd in the drive.

Last edited by beretta (2009-01-21 22:33:15)

beretta · 2009-01-23 14:55:55

To make the issue even stranger, it changed on bootup this morning:

:: Loading UDev uevents
 >    UDev uevent processing time: 179263ms

The ALSA error remained unchanged, however, so the two may be unrelated.

Is there really no one else seeing anything like this? I know some people have slow UDev, but it went from a couple of seconds to 3 minutes without any hardware change!

Wittfella · 2009-01-24 14:25:14

I had the same problem went I went to 2.6.28. It started spitting out reams of stack trace at each boot and got stuck on the udev timeout. The really irritating thing was that it seemed to do something different with every reboot.

Previously I had always blacklisted the pcspkr module to stop the annoying beeping. After many hours of trying different things with 2.6.28 I found that un-blacklisting it seemed to solve the problem. This doesn't really help you because I see you already tried pcspkr and snd_pcsp, but I think its interesting that my problem also seemed to revolved around pcspkr.

beretta · 2009-02-06 21:56:34

Well, the pcspkr and snd_pcsp don't really seem to have any change in the boot time, so I'm not certain why that error pops up. The problem has to be somewhere else, I think, but I don't know where else to look. It'd be nice to get a more verbose output of the uevent processing, and see if it's a particular call that's causing the problem or if the whole thing is just slow. Anyone know of any way to do such a thing?

beretta · 2009-02-09 17:24:52

Another symptom I've started to notice is that it takes forever for a usb flash drive to settle and mount (didn't see it before because I don't use usb drives often). I'm thinking it's related, because the cpu fan cranks all the way up gradually the same as I hear on boot when uevents are processing.

Are there really so few of us with this problem?

alienman · 2009-02-20 16:36:26

I also have some problems with udev an acpi modules, my laptop takes forever if it is running on battery when the process loading acpi modules starts, but as soon as I plug into ac, it starts loading very fast.

Some times it could be helped by pressing power off button when running on battery. I guess this is serious because it seems to be unusable for laptop users.

I have done 3 fresh installs and the problem persists even using ext4 with the new arch 2009.02 installer

beretta · 2009-02-21 18:02:37

Ok, after a lot of exploring, and using a trick I learned here http://bbs.archlinux.org/viewtopic.php?id=63320, I've been able to get a little more information.

On boot, everything proceeds normally, until the point where udev reports this:

UEVENT [Some time here] add /class/ieee1394_node/0090270001e158cf (ieee1394_node)
UEVENT [Some time here] add /devices/pci0000:00/0000:00:1e.0/0000:07:03.0/fw-host0/0090270001e158cf
UDEV   [Some time here] add /class/ieee1394_node/0090270001e158cf (ieee1394_node)
UDEV   [Some time here] add /devices/pci0000:00/0000:00:1e.0/0000:07:03.0/fw-host0/0090270001e158cf

The times are fractions of a millisecond apart, unsurprisingly, and at this point the system hangs for about 3 minutes. It resumes after that, but then scrolls by too quickly to be seen well. udevadm monitor spits out so much more stuff in the subsequent boot steps (all very quick, mind you) that I cannot scroll back to see the end. I was able to catch something about /device/platform/regulatory.0, however.

Now, looking at the output of lspci:

00:1e.0 PCI bridge: Intel Corporation 82801 PCI Bridge (rev 92)
00:1f.0 ISA bridge: Intel Corporation 82801IR (ICH9R) LPC Interface Controller (rev 02)
00:1f.2 RAID bus controller: Intel Corporation 82801 SATA RAID Controller (rev 02)
00:1f.3 SMBus: Intel Corporation 82801I (ICH9 Family) SMBus Controller (rev 02)
01:00.0 VGA compatible controller: nVidia Corporation G80 [GeForce 8800 GTS] (rev a2)
03:00.0 IDE interface: Marvell Technology Group Ltd. 88SE6101 single-port PATA133 interface (rev b1)
07:03.0 FireWire (IEEE 1394): Texas Instruments TSB43AB22/A IEEE-1394a-2000 Controller (PHY/Link)

00:1e.0 is the Intel PCI Bridge, and 07:03.0 is the FireWire port (which I actually don't use). If I'm understanding the cryptic udev messages correctly, it looks like the firewire is what's causing the hangup.

Any help from here?

Zibi1981 · 2009-02-23 18:18:29

beretta wrote:

Recently I upgraded my system (which I believe included the newer kernel, possibly a udev upgrade?) and now on boot, it halts at the line
:: Processing UDev uevents
and waits for over 2 minutes. I can catch a glimpse of a "timeout after 180 seconds" message as it flashes past when it starts moving again, then lose it quickly as everything else boots very quickly. I've also noticed a message when it starts of ALSA about a failure to recognize the sound card and using a "best guess".
Does anyone know off hand which modules should no longer be included with the new kernel? Here's whats in my line in rc.conf:
MOD_AUTOLOAD="yes"
MODULES=(e1000e slhc rt2x00usb rt73usb snd-mixer-oss  snd-pcm-oss 
snd-hwdep snd-page-alloc snd-pcm snd-timer snd snd-hda-intel soundcore usblp)
EDIT:
Here are the actual messages on boot (I rebooted with !slim in rc.conf):
:: Loading UDev uevents
devadm settle timeout of 180 seconds reached, the event queue contains:
   '/sys/module/snd_pcsp'  [1097]
   '/sys/class/scsi_generic/sg0'  [1080]
   '/sys/devices/pci0000:00/0000:00:1c.1/0000:03:00.0/host0/target0:0:0/0:0:0:0'
[1012]
   > UDev uevent processing time:  180216 ms

...
...

::Restoring ALSA Levels
Unknown hardware: "HDA-Intel" "SigmaTel STAC9271D" "HDA:83847627, 80863001, 001002
01" "0x8086" "0x3001"
Hardware is initialized using a guess method                               [FAIL]

I'm having very similar problem with ALSA related error message during boot-up, though my system doesn't seem to suffer form UDEV issue you described. The problem in my case started after I've inserted this line

options snd-hda-intel model=3stack-6ch-dig

into my /etc/modprobe.conf file in order to make my speakers mute when I plug-in headphones. I solved this problem partially with this line present in modprobe.conf, but now I'm getting error messages. It doesn't seem to affect my OS though, as I have sound working properly. What could be the cause of this?

beretta · 2009-03-12 01:52:40

The latest kernel and udev update has made the problem worse. Not only does the udev processing timeout, but it also takes forever to load some of the daemons, and loading slim also takes an excessively long time. Total boot time is now almost 5 minutes, and it takes nearly that long again for slim to come up! (This isn't legacy hardware, for crying out loud, it was bought top-of-the-line just a year or two ago.)

I've installed bootchart, and included the image here. Unfortunately it's so large, and I'm so unfamiliar with what it tells me, I can't get much out of it just yet. If anyone's got a good eye or a bit of time, could you point me to what I'm looking for with it?

EDIT:: That link gave a small version of the chart. I'm tired, so I'll try to get it linked to a better version later. Also, removing the explicit modules in /etc/rc.conf as suggested in another thread didn't help.

Last edited by beretta (2009-04-15 14:14:57)

beretta · 2009-03-13 15:21:17

Here's a link to the full-size bootchart image. Something is clearly messed up, as the picture is so much larger than most people's bootchart images I've seen posted here.

Looking at it more carefully, there are a whole lot of sleeps and ignore-removes in the image. ???

Last edited by beretta (2009-04-15 14:14:44)

beretta · 2009-04-15 14:14:29

Believe it or not, after the new install I discovered the problem. The new install was great, and even a better system than before, so I'm not broken up about it at all.

Here's the problem: I had added a rules file to udev as per the description in this thread in order to use my Creative Zen mp3 player:

[b]65-libmtp.rules[/b]
SUBSYSTEM!="usb_device", ACTION!="add", GOTO="libmtp_rules_end"

# Creative Zen 8Gb mp3 player
SYSFS={idVendor}=="041e", SYSFS{idProduct}="4157", SYMLINK+="libmtp-%k", MODE="666", GROUP="audio"

With this file in the rules directory, bootup was painfully slow. Once I removed the file, it went back to its normal behavior.

Anyone know why?

::: I removed the bootchart images above to make this thread more readable.

Arch Linux

#1 2009-01-21 21:48:20

udev timeout, slow boot

#2 2009-01-21 22:10:05

Re: udev timeout, slow boot

#3 2009-01-23 14:55:55

Re: udev timeout, slow boot

#4 2009-01-24 14:25:14

Re: udev timeout, slow boot

#5 2009-02-06 21:56:34

Re: udev timeout, slow boot

#6 2009-02-09 17:24:52

Re: udev timeout, slow boot

#7 2009-02-20 16:36:26

Re: udev timeout, slow boot

#8 2009-02-21 18:02:37

Re: udev timeout, slow boot

#9 2009-02-23 18:18:29

Re: udev timeout, slow boot

#10 2009-03-12 01:52:40

Re: udev timeout, slow boot

#11 2009-03-13 15:21:17

Re: udev timeout, slow boot

#12 2009-04-15 14:14:29

Re: udev timeout, slow boot

Board footer