Bugzilla will be upgraded to version 5.0 on a still to be determined date in the near future. The original upgrade date has been delayed.
Bug 597232 - modprobe snd-hda-intel hangs
modprobe snd-hda-intel hangs
Status: CLOSED NOTABUG
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: module-init-tools (Show other bugs)
6.0
All Linux
high Severity high
: beta
: ---
Assigned To: Jon Masters
qe-baseos-daemons
: Regression
: 598040 598108 (view as bug list)
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2010-05-28 09:15 EDT by Lubos Kocman
Modified: 2010-06-01 11:25 EDT (History)
13 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2010-06-01 11:25:26 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
lspci from t400 (2.39 KB, text/plain)
2010-05-28 10:45 EDT, Lubos Kocman
no flags Details

  None (edit)
Description Lubos Kocman 2010-05-28 09:15:21 EDT
Description of problem:

System became unbootable installing today's updates from Latest RHEL 6 (Thinkpad T400 / x86_64).

It hangs on Starting udev:

booted with  nomodeset

Starting udev: udev[485]: worker [512] unexpectedly returned with status 0x0100

udevd[485]: worker[512] failed while handling '/devices/pci0000:00/0000:00:1b/0'


when booted without nomodeset:

I'm able to see messages mentioning LXVIDEO on the end of udev stderr.


How reproducible:



Steps to Reproduce:
1.Install RHEL6.x86_64 updates from May 28 on Thinkpad T400

Actual results:

Udev hanging

Expected results:

System should boot normally

Additional info:

The same problem occures with older kernels that worked for me.
Comment 2 Harald Hoyer 2010-05-28 09:30:05 EDT
what is the output of "lspci" ?
Comment 3 Harald Hoyer 2010-05-28 09:33:05 EDT
do you see more messages regarding modprobe?
Comment 4 Harald Hoyer 2010-05-28 09:34:29 EDT
most likely a video kernel driver problem
Comment 5 Lubos Kocman 2010-05-28 10:45:37 EDT
Created attachment 417642 [details]
lspci from t400
Comment 6 Lubos Kocman 2010-05-28 10:57:41 EDT
!!! booted with blacklisted snd-hda-intel

Some useful info from mentioned T400

lkocman@ThinkPad T400$ rpm -qa | grep kernel
kernel-firmware-2.6.32-30.el6.noarch
kernel-devel-2.6.32-28.el6.x86_64
kernel-headers-2.6.32-30.el6.x86_64
kernel-2.6.32-27.el6.x86_64
abrt-addon-kerneloops-1.1.4-1.el6.x86_64
kernel-devel-2.6.32-27.el6.x86_64
kernel-devel-2.6.32-30.el6.x86_64
kernel-2.6.32-28.el6.x86_64
dracut-kernel-004-19.el6.noarch
kernel-2.6.32-30.el6.x86_64

All older present kernels suffer from the same issue ...
I'd like to mention again that the issue started today after yum update

============================================================================
modprobe snd-hda-intel hangs (following output is during modprobe)
============================================================================
lkocman@ThinkPad T400$ ps ax | grep insmod | grep -v grep
lkocman@ThinkPad T400$ 

lkocman@ThinkPad T400$ ps ax | grep modprobe | grep -v grep
8753 pts/1    D+     0:00 modprobe snd_hda_intel
8761 ?        S      0:07 /sbin/modprobe -q -- snd_hda_codec_id:14f15051

lkocman@ThinkPad T400$ sudo tail -30  /var/log/messages
May 28 16:50:46 dhcp-29-7 udevd[499]: seq 1913 queued, 'add' 'module'
May 28 16:50:46 dhcp-29-7 udevd[499]: passed 135 bytes to monitor 0x14859f0
May 28 16:50:46 dhcp-29-7 udevd-work[8181]: seq 1913 running
May 28 16:50:46 dhcp-29-7 udevd-work[8181]: RUN 'socket:@/org/freedesktop/hal/udev_event' /etc/udev/rules.d/90-hal.rules:2
May 28 16:50:46 dhcp-29-7 udevd-work[8181]: passed 125 bytes to monitor 0x14859f0
May 28 16:50:46 dhcp-29-7 udevd-work[8181]: passed -1 bytes to monitor 0x14c6780
May 28 16:50:46 dhcp-29-7 udevd-work[8181]: seq 1913 processed with 0
May 28 16:50:46 dhcp-29-7 udevd[499]: seq 1913 done with 0
May 28 16:50:46 dhcp-29-7 udevd-work[8177]: 'udev-acl --action=add --device=/dev/snd/seq' returned with exitcode 0
May 28 16:50:46 dhcp-29-7 udevd-work[8177]: passed 219 bytes to monitor 0x1646ec0
May 28 16:50:46 dhcp-29-7 udevd-work[8177]: passed -1 bytes to monitor 0x14c6430
May 28 16:50:46 dhcp-29-7 udevd-work[8177]: seq 1912 processed with 0
May 28 16:50:46 dhcp-29-7 udevd[499]: seq 1912 done with 0
May 28 16:50:46 dhcp-29-7 udevd[499]: seq 1914 queued, 'add' 'module'
May 28 16:50:46 dhcp-29-7 udevd[499]: passed 139 bytes to monitor 0x14859f0
May 28 16:50:46 dhcp-29-7 udevd-work[8177]: seq 1914 running
May 28 16:50:46 dhcp-29-7 udevd-work[8177]: RUN 'socket:@/org/freedesktop/hal/udev_event' /etc/udev/rules.d/90-hal.rules:2
May 28 16:50:46 dhcp-29-7 udevd-work[8177]: passed 133 bytes to monitor 0x1646ec0
May 28 16:50:46 dhcp-29-7 udevd-work[8177]: passed -1 bytes to monitor 0x14c6430
May 28 16:50:46 dhcp-29-7 udevd-work[8177]: seq 1914 processed with 0
May 28 16:50:46 dhcp-29-7 udevd[499]: seq 1914 done with 0
May 28 16:50:46 dhcp-29-7 udevd[499]: seq 1915 queued, 'add' 'module'
May 28 16:50:46 dhcp-29-7 udevd[499]: passed 139 bytes to monitor 0x14859f0
May 28 16:50:46 dhcp-29-7 udevd-work[8177]: seq 1915 running
May 28 16:50:46 dhcp-29-7 udevd-work[8177]: RUN 'socket:@/org/freedesktop/hal/udev_event' /etc/udev/rules.d/90-hal.rules:2
May 28 16:50:46 dhcp-29-7 udevd-work[8177]: passed 133 bytes to monitor 0x1646ec0
May 28 16:50:46 dhcp-29-7 udevd-work[8177]: passed -1 bytes to monitor 0x14c6430
May 28 16:50:46 dhcp-29-7 udevd-work[8177]: seq 1915 processed with 0
May 28 16:50:46 dhcp-29-7 udevd[499]: seq 1915 done with 0
May 28 16:50:46 dhcp-29-7 kernel: HDA Intel 0000:00:1b.0: PCI INT B -> GSI 17 (level, low) -> IRQ 17
Comment 7 William Cohen 2010-05-28 11:37:44 EDT
See the same problem on Thinkpad T510. Was able to boot with the following added to /etc/modprobe.d/blacklist.conf:

blacklist snd-hda-intel
Comment 8 William Cohen 2010-05-28 11:39:45 EDT
See the following output from dmesg after a "modprobe snd_hda_intel":


HDA Intel 0000:00:1b.0: PCI INT B -> GSI 17 (level, low) -> IRQ 17
  alloc irq_desc for 35 on node -1
  alloc kstat_irqs on node -1
HDA Intel 0000:00:1b.0: irq 35 for MSI/MSI-X
HDA Intel 0000:00:1b.0: setting latency timer to 64
INFO: task modprobe:10600 blocked for more than 120 seconds.
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
modprobe      D ffff880137c23280     0 10600  10580 0x00000084
 ffff88010d085988 0000000000000086 0000000000000000 ffff880028396840
 ffff88010d085908 ffffffff8104e5dc ffff88010d085928 000000010012791a
 ffff8800a1a866b0 ffff88010d085fd8 00000000000103b8 ffff8800a1a866b0
Call Trace:
 [<ffffffff8104e5dc>] ? enqueue_task+0x5c/0x70
 [<ffffffff814d4af5>] schedule_timeout+0x225/0x2f0
 [<ffffffff8108ff96>] ? autoremove_wake_function+0x16/0x40
 [<ffffffff8104efa9>] ? __wake_up_common+0x59/0x90
 [<ffffffff8101aea6>] ? native_read_tsc+0x6/0x20
 [<ffffffff814d474d>] wait_for_common+0x11d/0x190
 [<ffffffff8105b980>] ? default_wake_function+0x0/0x20
 [<ffffffff8108af31>] ? __queue_work+0x41/0x50
 [<ffffffff814d487d>] wait_for_completion+0x1d/0x20
 [<ffffffff810894b6>] call_usermodehelper_exec+0xf6/0x120
 [<ffffffffa06880c3>] ? snd_hda_codec_configure+0x2c3/0x4f0 [snd_hda_codec]
 [<ffffffff8108966b>] __request_module+0x18b/0x210
 [<ffffffff8125a164>] ? snprintf+0x34/0x40
 [<ffffffffa06880c3>] snd_hda_codec_configure+0x2c3/0x4f0 [snd_hda_codec]
 [<ffffffffa03811a0>] ? azx_send_cmd+0x0/0x1c0 [snd_hda_intel]
 [<ffffffffa0380ef0>] ? azx_get_response+0x0/0x2b0 [snd_hda_intel]
 [<ffffffffa0370039>] ? crypt_resume+0x9/0x20 [dm_crypt]
 [<ffffffffa03820ba>] azx_probe+0x881/0x985 [snd_hda_intel]
 [<ffffffff8126d8a7>] local_pci_probe+0x17/0x20
 [<ffffffff8126ea71>] pci_device_probe+0x101/0x120
 [<ffffffff8132dc52>] ? driver_sysfs_add+0x62/0x90
 [<ffffffff8132ddf0>] driver_probe_device+0xa0/0x2a0
 [<ffffffff8132e09b>] __driver_attach+0xab/0xb0
 [<ffffffff8132dff0>] ? __driver_attach+0x0/0xb0
 [<ffffffff8132d064>] bus_for_each_dev+0x64/0x90
 [<ffffffff8132db8e>] driver_attach+0x1e/0x20
 [<ffffffff8132d4a0>] bus_add_driver+0x200/0x300
 [<ffffffff812524d8>] ? kset_find_obj+0x38/0x80
 [<ffffffff8132e3c6>] driver_register+0x76/0x140
 [<ffffffff814d9345>] ? notifier_call_chain+0x55/0x80
 [<ffffffff8126ecc6>] __pci_register_driver+0x56/0xd0
 [<ffffffff810953a5>] ? __blocking_notifier_call_chain+0x65/0x80
 [<ffffffffa0280000>] ? alsa_card_azx_init+0x0/0x20 [snd_hda_intel]
 [<ffffffffa028001e>] alsa_card_azx_init+0x1e/0x20 [snd_hda_intel]
 [<ffffffff8100a04c>] do_one_initcall+0x3c/0x1d0
 [<ffffffff810adfdf>] sys_init_module+0xdf/0x250
 [<ffffffff81013172>] system_call_fastpath+0x16/0x1b
Comment 9 Christopher Aillon 2010-05-28 17:46:46 EDT
This is not fixed by using older kernels, however downgrading module-init-tools to 3.9-10.el6 does fix this, so moving over to m-i-t.
Comment 10 Christopher Aillon 2010-05-28 17:47:44 EDT
Note that after I performed the workaround in comment 7, I still had no network.  I undid that change and reverted to module-init-tools-3.9-10.el6.x86_64 which solved both problems.
Comment 11 Phil Knirsch 2010-05-31 07:05:25 EDT
*** Bug 598040 has been marked as a duplicate of this bug. ***
Comment 12 Martin Cermak 2010-06-01 03:18:22 EDT
Also faced this problem this morning with lenovo T500. Added to /etc/modprobe.d/blacklist.conf:

blacklist snd-hda-intel    

But still udev start more slowly than it did before..

Good battle this morning ;-)
Comment 13 Chris Ward 2010-06-01 05:01:51 EDT
*** Bug 598108 has been marked as a duplicate of this bug. ***
Comment 14 Chris Ward 2010-06-01 05:02:58 EDT
Hitting this too. Lenovo T61 Intel.

blacklist snd-hda-intel works for me... but not ideal obviously.
Comment 16 Jon Masters 2010-06-01 11:25:26 EDT
This bug is caused by the implementation of the fix to 515413. That bug implements an elaborate mechanism in modprobe to run only one modprobe instance at a time, which does handle direct child dependences, but does not handle indirect ones by means of a synchronous call into the kernel. It is possible to have modprobe also exclude calls made directly from u_m_h (the kernel helper) but this gets a lot more complex than just doing the one-at-a-time solution in udev.

So, the fix for 515413 is being reverted, we're going with the udev option, and not until after the beta refresh at this point. Sorry for any inconvenience.

Jon.

Note You need to log in before you can comment on or make changes to this bug.