New Kernel 3.2.1: Waiting for UDev uevents to be progressed [FAIL]

swordfish · 2012-01-14 19:12:12

Hi there,

recently I've installed Arch to an external USB-HDD of my Lenovo Thinkpad Edge E520. Until today (Jan 14th) the system was booting quite fast. But a "sudo pacman -Syu" this morning led to a slowed down boot. The system hangs at:

Waiting for UDev uevents to be progressed

and after 30 seconds (which is defined in /etc/rc.conf) the [BUSY] sign switches to [FAIL]. After that the boot-process stops again, when the "laptop-mode" Daemon has to be loaded.

After that, the system boots and runs quite normal *sigh*.

I'm not sure, but I think this behaviour is maybe a result of the new Kernel 3.2.1 that I got this morning. Do you think this is possible? Or has anyone else noticed this behaviour?

This is - for example - the output of /var/log/errors.log:

Jan 14 19:10:48 localhost kernel: [    3.268783] sd 6:0:0:0: [sdb] No Caching mode page present
Jan 14 19:10:48 localhost kernel: [    3.268887] sd 6:0:0:0: [sdb] Assuming drive cache: write through
Jan 14 19:10:48 localhost kernel: [    3.270896] sd 6:0:0:0: [sdb] No Caching mode page present
Jan 14 19:10:48 localhost kernel: [    3.270967] sd 6:0:0:0: [sdb] Assuming drive cache: write through
Jan 14 19:10:48 localhost kernel: [    3.294608] sd 6:0:0:0: [sdb] No Caching mode page present
Jan 14 19:10:48 localhost kernel: [    3.294667] sd 6:0:0:0: [sdb] Assuming drive cache: write through
Jan 14 19:10:50 localhost /usr/sbin/crond[551]: (CRON) INFO (Syslog will be used instead of sendmail.): File or Directory not found
Jan 14 19:10:57 localhost dhcpcd[898]: dhcpcd not running
Jan 14 19:10:57 localhost dhcpcd[905]: dhcpcd not running
Jan 14 19:11:16 localhost udevd[176]: error: can not open '/sys/devices/pci0000:00/0000:00:1c.3/0000:08:00.0/firmware/0000:08:00.0/loading'

The last line seems to be interesting, but it didn't tell me anything .

The boot-logfile just tells me:

Sat Jan 14 19:10:45 2012: :: Starting UDev Daemon    [BUSY]    [DONE] 
Sat Jan 14 19:10:45 2012: :: Triggering UDev uevents    [BUSY]    [DONE] 
Sat Jan 14 19:10:45 2012: :: Waiting for UDev uevents to be processed    [BUSY]    [FAIL]

This is the relevant output of the daemon.log:

Jan 14 19:10:48 localhost [    1.400939] udevd[44]: starting version 177
Jan 14 19:10:48 localhost [    6.169773] udevd[171]: starting version 177
Jan 14 19:10:50 localhost dhclient: isc-dhclient-4.2.3-P1
Jan 14 19:10:50 localhost dhclient: isc-dhclient-4.2.3-P1
Jan 14 19:10:50 localhost laptop-mode: Laptop mode 
Jan 14 19:10:50 localhost laptop-mode: enabled, not active
Jan 14 19:10:57 localhost dhcpcd[898]: dhcpcd not running
Jan 14 19:10:57 localhost dhcpcd[905]: dhcpcd not running
Jan 14 19:10:59 localhost dhcpcd[909]: version 5.2.12 starting
Jan 14 19:11:00 localhost dhcpcd[909]: eth0: rebinding lease of 192.168.178.25
Jan 14 19:11:00 localhost dhcpcd[909]: eth0: acknowledged 192.168.178.25 from 192.168.178.1
Jan 14 19:11:00 localhost dhcpcd[909]: eth0: checking for 192.168.178.25
Jan 14 19:11:04 localhost dhcpcd[909]: eth0: leased 192.168.178.25 for 864000 seconds
Jan 14 19:11:04 localhost dhcpcd[909]: forked to background, child pid 931
Jan 14 19:11:16 localhost udevd[176]: error: can not open '/sys/devices/pci0000:00/0000:00:1c.3/0000:08:00.0/firmware/0000:08:00.0/loading'
Jan 14 19:11:19 localhost acpid: starting up with netlink and the input layer
Jan 14 19:11:19 localhost acpid: 4 rules loaded
Jan 14 19:11:19 localhost acpid: waiting for events: event logging is off
Jan 14 19:11:20 localhost acpid: client connected from 1172[0:0]
Jan 14 19:11:20 localhost acpid: 1 client rule loaded
Jan 14 19:11:31 localhost dbus[473]: [system] Activating service name='org.freedesktop.ConsoleKit' (using servicehelper)
Jan 14 19:11:31 localhost dbus[473]: [system] Activating service name='org.freedesktop.PolicyKit1' (using servicehelper)
Jan 14 19:11:31 localhost polkitd[1271]: started daemon version 0.103 using authority implementation `local' version `0.103'
Jan 14 19:11:31 localhost dbus[473]: [system] Successfully activated service 'org.freedesktop.PolicyKit1'
Jan 14 19:11:31 localhost dbus[473]: [system] Successfully activated service 'org.freedesktop.ConsoleKit'

Any ideas why the boot-process stalls at the udev uevents?

litemotiv · 2012-01-14 19:24:32

Jan 14 19:11:16 localhost udevd[176]: error: can not open '/sys/devices/pci0000:00/0000:00:1c.3/0000:08:00.0/firmware/0000:08:00.0/loading'

https://bugs.archlinux.org/task/27938

Also, when using the [testing] repo please post in the appropriate subforum.

ewaller · 2012-01-14 19:27:56

Moving to the testing subforum

swordfish · 2012-01-14 19:31:49

litemotiv wrote:

Also, when using the [testing] repo please post in the appropriate subforum.

Ooops, sorry - overlooked it

ewaller wrote:

Moving to the testing subforum

Thanks a lot !

mundigranja · 2012-01-15 02:00:07

Do you use a wireless device that requires brcmsmac? I solved it by adding brcmsmac in MODULES section in /etc/rc.conf

swordfish · 2012-01-15 10:56:43

mundigranja wrote:

Do you use a wireless device that requires brcmsmac? I solved it by adding brcmsmac in MODULES section in /etc/rc.conf

Nope, it's a Realtek device - rtl8192ce. Seems as if this problem is mostly related to wifi devices and their firmware. When I look into dmesg, I find this:

[   67.522375] rtl8192ce:rtl92c_init_sw_vars():<0-0> Failed to request firmware!
[   67.522378] rtlwifi:rtl_pci_probe():<0-0> Can't init_sw_vars.
[   67.522408] rtl8192ce 0000:08:00.0: PCI INT A disabled

When the system has already booted, I can reactivate the wireless by

modprobe -r rtl8192ce

and then

modprobe rtl8192ce

But i will try out your solution with the MODULES section in rc.conf. Thanks for the hint !

swordfish · 2012-01-15 11:16:50

mundigranja wrote:

I solved it by adding brcmsmac in MODULES section in /etc/rc.conf

Yep, that's working ! I added rtl8192ce to the MODULES section of /etc/rc.conf and now the system is booting quite fast again.

/var/log/boot shows:

Sun Jan 15 12:04:49 2012: :: Adjusting system time and setting kernel timezone  
  [BUSY]    [DONE] 
Sun Jan 15 12:04:49 2012: :: Starting UDev Daemon    [BUSY]    [DONE] 
Sun Jan 15 12:04:49 2012: :: Triggering UDev uevents    [BUSY]    [DONE] 
Sun Jan 15 12:04:49 2012: :: Loading User-specified Modules    [BUSY]    [DONE] 
Sun Jan 15 12:04:49 2012: :: Waiting for UDev uevents to be processed    [BUSY]    [DONE]

and in dmesg:

[    6.547970] rtl8192ce 0000:08:00.0: PCI INT A -> GSI 19 (level, low) -> IRQ 19
[    6.547980] rtl8192ce 0000:08:00.0: setting latency timer to 64
[    6.875461] ieee80211 phy0: Selected rate control algorithm 'rtl_rc'
[    6.876544] rtlwifi: wireless switch is on
[   14.526217] rtl8192c_common: Loading firmware file rtlwifi/rtl8192cfw.bin
[   14.977485] rtl8192c_common: Loading firmware file rtlwifi/rtl8192cfw.bin
[   22.459984] rtl8192c_common: Loading firmware file rtlwifi/rtl8192cfw.bin
[   39.089139] rtl8192c_common: Loading firmware file rtlwifi/rtl8192cfw.bin

So, this seems to be a good workaround

mundigranja · 2012-01-15 12:18:01

I'm glad that it worked to you :-)

Arch Linux

#1 2012-01-14 19:12:12

New Kernel 3.2.1: Waiting for UDev uevents to be progressed [FAIL]

#2 2012-01-14 19:24:32

Re: New Kernel 3.2.1: Waiting for UDev uevents to be progressed [FAIL]

#3 2012-01-14 19:27:56

Re: New Kernel 3.2.1: Waiting for UDev uevents to be progressed [FAIL]

#4 2012-01-14 19:31:49

Re: New Kernel 3.2.1: Waiting for UDev uevents to be progressed [FAIL]

#5 2012-01-15 02:00:07

Re: New Kernel 3.2.1: Waiting for UDev uevents to be progressed [FAIL]

#6 2012-01-15 10:56:43

Re: New Kernel 3.2.1: Waiting for UDev uevents to be progressed [FAIL]

#7 2012-01-15 11:16:50

Re: New Kernel 3.2.1: Waiting for UDev uevents to be progressed [FAIL]

#8 2012-01-15 12:18:01

Re: New Kernel 3.2.1: Waiting for UDev uevents to be progressed [FAIL]

Board footer