Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1755232Ab3GTXUT (ORCPT ); Sat, 20 Jul 2013 19:20:19 -0400 Received: from mail.tomasu.net ([64.85.170.232]:39283 "EHLO mail.tomasu.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1754861Ab3GTXUR (ORCPT ); Sat, 20 Jul 2013 19:20:17 -0400 From: Thomas Fjellstrom To: LKML Subject: Re: hung task with 3.9.8/3.10.1 Date: Sat, 20 Jul 2013 17:19:30 -0600 Message-ID: <31240603.zcuBEB4roc@balsa> User-Agent: KMail/4.10.5 (Linux/3.9-1-amd64; KDE/4.10.5; x86_64; ; ) In-Reply-To: <137450198.fYZy8Ria9U@balsa> References: <137450198.fYZy8Ria9U@balsa> MIME-Version: 1.0 Content-Transfer-Encoding: 7Bit Content-Type: text/plain; charset="us-ascii" Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 18154 Lines: 279 On Sat 20 July 2013 08:21:38 Thomas Fjellstrom wrote: > I recently picked up an older IBM System x3650 server for some > virtualization and web stuff, and after installing (oldstable) and > upgrading (curent sid) debian, it hangs for a while on bootup trying to > modprobe some driver (logs to follow). It booted fine with the old debian > 2.6.32 kernel, but I felt it was a good idea not to use an ancient kernel. > > [ 240.592039] INFO: task modprobe:597 blocked for more than 120 seconds. > [ 240.592101] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables > this message. [ 240.592161] modprobe D ffff88013fd53ec0 0 597 > 566 0x20020004 [ 240.592166] ffff880137ddd7f0 0000000000000082 > ffff88013aea00c0 0000000000013ec0 [ 240.592171] ffff8801395b7fd8 > ffff8801395b7fd8 ffff880137ddd7f0 ffff8801392d8c00 [ 240.592175] > 0000000000000000 0000000000000000 ffff8801392d8f78 0000000000000000 [ > 240.592179] Call Trace: > [ 240.592198] [] ? i801_transaction+0xa4/0xe9 [i2c_i801] > [ 240.592206] [] ? abort_exclusive_wait+0x79/0x79 [ > 240.592211] [] ? i801_access+0x7a6/0x888 [i2c_i801] [ > 240.592217] [] ? __wake_up_common+0x3f/0x71 > [ 240.592223] [] ? _raw_spin_unlock_irqrestore+0xc/0xd > [ 240.592228] [] ? ep_poll_callback+0xe0/0xf9 > [ 240.592235] [] ? i2c_smbus_xfer+0xc3/0x11d [i2c_core] > [ 240.592241] [] ? idr_find.constprop.13+0x25/0x30 > [i2c_core] [ 240.592247] [] ? > i2c_default_probe+0x83/0xd0 [i2c_core] [ 240.592252] [] > ? idr_find.constprop.13+0x25/0x30 [i2c_core] [ 240.592258] > [] ? i2c_check_addr_busy+0x2c/0x42 [i2c_core] [ > 240.592263] [] ? i2c_do_add_adapter+0x9d/0x1ff > [i2c_core] [ 240.592269] [] ? > kobject_uevent_env+0x3f8/0x43a [ 240.592274] [] ? > i2c_do_add_adapter+0x1ff/0x1ff [i2c_core] [ 240.592280] > [] ? i2c_do_add_adapter+0x1ff/0x1ff [i2c_core] [ > 240.592285] [] ? bus_for_each_dev+0x4b/0x7c > [ 240.592291] [] ? i2c_do_add_adapter+0x1ff/0x1ff > [i2c_core] [ 240.592296] [] ? > i2c_for_each_dev+0x29/0x3f [i2c_core] [ 240.592302] [] > ? i2c_register_driver+0x7a/0x9f [i2c_core] [ 240.592312] > [] ? 0xffffffffa0060fff > [ 240.592317] [] ? do_one_initcall+0x74/0x12a > [ 240.592321] [] ? 0xffffffffa0060fff > [ 240.592326] [] ? load_module+0x1ae4/0x1dcd > [ 240.592330] [] ? free_notes_attrs+0x3c/0x3c > [ 240.592335] [] ? sys_init_module+0x9e/0xab > [ 240.592340] [] ? sysenter_dispatch+0x7/0x21 > [ 240.592344] INFO: task modprobe:674 blocked for more than 120 seconds. > [ 240.592401] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables > this message. [ 240.592460] modprobe D ffff88013fc93ec0 0 674 > 528 0x20020006 [ 240.592463] ffff880137e05100 0000000000000082 > ffff88013ae9f7b0 0000000000013ec0 [ 240.592468] ffff8801386d1fd8 > ffff8801386d1fd8 ffff880137e05100 ffffffffa01f20e0 [ 240.592472] > ffff880137e05100 ffffffffa01f20e4 0000000000000002 0000000000000000 [ > 240.592476] Call Trace: > [ 240.592482] [] ? schedule_preempt_disabled+0x5/0x6 > [ 240.592486] [] ? > __mutex_lock_common.isra.6+0x145/0x161 [ 240.592493] [] > ? i2c_register_adapter+0x1f6/0x1f6 [i2c_core] [ 240.592496] > [] ? mutex_lock+0x17/0x27 > [ 240.592502] [] ? i2c_add_adapter+0x11/0x59 [i2c_core] > [ 240.592507] [] ? __i2c_bit_add_bus+0x33/0x284 > [i2c_algo_bit] [ 240.592546] [] ? > radeon_i2c_create+0x1b8/0x1ea [radeon] [ 240.592570] [] > ? radeon_combios_i2c_init+0x5b/0x227 [radeon] [ 240.592599] > [] ? radeon_modeset_init+0x8da/0x916 [radeon] [ > 240.592629] [] ? radeon_ib_ring_tests+0x3b/0x9b [radeon] > [ 240.592652] [] ? radeon_driver_load_kms+0xb1/0xf5 > [radeon] [ 240.592664] [] ? drm_get_pci_dev+0x152/0x259 > [drm] [ 240.592685] [] ? radeon_pci_probe+0xd4/0xf6 > [radeon] [ 240.592706] [] ? radeon_pci_probe+0xe6/0xf6 > [radeon] [ 240.592711] [] ? local_pci_probe+0x33/0x58 > [ 240.592715] [] ? driver_probe_device+0x1b0/0x1b0 > [ 240.592719] [] ? pci_device_probe+0xba/0xde > [ 240.592723] [] ? driver_probe_device+0x92/0x1b0 > [ 240.592727] [] ? __driver_attach+0x53/0x73 > [ 240.592730] [] ? bus_for_each_dev+0x4b/0x7c > [ 240.592735] [] ? bus_add_driver+0xd5/0x1f4 > [ 240.592739] [] ? 0xffffffffa0312fff > [ 240.592743] [] ? driver_register+0x87/0xfe > [ 240.592747] [] ? 0xffffffffa0312fff > [ 240.592750] [] ? do_one_initcall+0x74/0x12a > [ 240.592754] [] ? 0xffffffffa0312fff > [ 240.592758] [] ? load_module+0x1ae4/0x1dcd > [ 240.592762] [] ? free_notes_attrs+0x3c/0x3c > [ 240.592766] [] ? sys_init_module+0x9e/0xab > [ 240.592770] [] ? sysenter_dispatch+0x7/0x21 > > These are the hung tasks: > > root 597 0.0 0.0 3988 688 ? D 06:25 0:00 > /sbin/modprobe -b > dmi:bvnIBM:bvr-[GGE146BUS-1.17]-:bd12/11/2009:svnIBM:pnIBMSystemx3650-[7979 > AC1]-:pvr:rvnIBM:rnSystemPlanar:rvr:cvnIBM:ct17:cvr: root 674 0.0 > 0.0 5104 1736 ? D 06:25 0:00 /sbin/modprobe -b > pci:v00001002d0000515Esv00001014sd00000305bc03sc00i00 > > I've tried debian's 3.9 and 3.10 kernel. > > Is this a known issue? Maybe I need to provide some kind of boot parameter? I've done a reinstall because I goofed and booted the wrong pxe image. It was running x86 instead of amd64. All fixed now, and the problem still persists. [ 240.436030] INFO: task modprobe:524 blocked for more than 120 seconds. [ 240.436093] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 240.436153] modprobe D ffff88013fd93fc0 0 524 521 0x00000004 [ 240.436158] ffff880138a5e100 0000000000000082 0000000000013fc0 ffff880139659fd8 [ 240.436163] ffff880139659fd8 ffff880138a5e100 ffff880139659cd0 ffff880139a03064 [ 240.436168] ffff880139a03060 0000000000000000 ffff880139a03068 ffffffff8137c77a [ 240.436172] Call Trace: [ 240.436183] [] ? schedule_preempt_disabled+0x5/0x6 [ 240.436187] [] ? __mutex_lock_common.isra.9+0x152/0x1e2 [ 240.436193] [] ? __device_attach+0x31/0x31 [ 240.436202] [] ? mutex_lock+0x16/0x25 [ 240.436206] [] ? __driver_attach+0x28/0x73 [ 240.436210] [] ? __device_attach+0x31/0x31 [ 240.436215] [] ? bus_for_each_dev+0x6b/0x75 [ 240.436219] [] ? bus_add_driver+0xeb/0x1f0 [ 240.436223] [] ? driver_register+0x82/0xeb [ 240.436235] [] ? 0xffffffffa0224fff [ 240.436243] [] ? shpcd_init+0x1b/0x1000 [shpchp] [ 240.436247] [] ? 0xffffffffa0224fff [ 240.436253] [] ? do_one_initcall+0x74/0x106 [ 240.436259] [] ? load_module+0x127a/0x1dfc [ 240.436263] [] ? store_uevent+0x32/0x32 [ 240.436268] [] ? SyS_init_module+0x9c/0xa9 [ 240.436273] [] ? system_call_fastpath+0x16/0x1b [ 240.436278] INFO: task modprobe:535 blocked for more than 120 seconds. [ 240.436335] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 240.436394] modprobe D ffff88013fd93fc0 0 535 526 0x00000004 [ 240.436398] ffff8801386dd770 0000000000000086 0000000000013fc0 ffff880138489fd8 [ 240.436403] ffff880138489fd8 ffff8801386dd770 ffff880138489cd0 ffff880139a03064 [ 240.436407] ffff880139a03060 0000000000000000 ffff880139a03068 ffffffff8137c77a [ 240.436411] Call Trace: [ 240.436416] [] ? schedule_preempt_disabled+0x5/0x6 [ 240.436420] [] ? __mutex_lock_common.isra.9+0x152/0x1e2 [ 240.436424] [] ? __device_attach+0x31/0x31 [ 240.436428] [] ? mutex_lock+0x16/0x25 [ 240.436431] [] ? __driver_attach+0x28/0x73 [ 240.436435] [] ? __device_attach+0x31/0x31 [ 240.436439] [] ? bus_for_each_dev+0x6b/0x75 [ 240.436443] [] ? bus_add_driver+0xeb/0x1f0 [ 240.436447] [] ? driver_register+0x82/0xeb [ 240.436451] [] ? 0xffffffffa02c8fff [ 240.436461] [] ? ioat_init_module+0x5e/0x1000 [ioatdma] [ 240.436465] [] ? 0xffffffffa02c8fff [ 240.436468] [] ? do_one_initcall+0x74/0x106 [ 240.436473] [] ? load_module+0x127a/0x1dfc [ 240.436476] [] ? store_uevent+0x32/0x32 [ 240.436482] [] ? SyS_init_module+0x9c/0xa9 [ 240.436486] [] ? system_call_fastpath+0x16/0x1b [ 240.436489] INFO: task modprobe:536 blocked for more than 120 seconds. [ 240.436547] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 240.436606] modprobe D ffff88013fc93fc0 0 536 527 0x00000004 [ 240.436610] ffff880138a28770 0000000000000082 0000000000013fc0 ffff88013848bfd8 [ 240.436614] ffff88013848bfd8 ffff880138a28770 ffff88013848bcd8 ffff880139a03064 [ 240.436618] ffff880139a03060 0000000000000000 ffff880139a03068 ffffffff8137c77a [ 240.436622] Call Trace: [ 240.436627] [] ? schedule_preempt_disabled+0x5/0x6 [ 240.436631] [] ? __mutex_lock_common.isra.9+0x152/0x1e2 [ 240.436635] [] ? __device_attach+0x31/0x31 [ 240.436639] [] ? mutex_lock+0x16/0x25 [ 240.436643] [] ? __driver_attach+0x28/0x73 [ 240.436647] [] ? __device_attach+0x31/0x31 [ 240.436651] [] ? bus_for_each_dev+0x6b/0x75 [ 240.436655] [] ? bus_add_driver+0xeb/0x1f0 [ 240.436659] [] ? driver_register+0x82/0xeb [ 240.436663] [] ? 0xffffffffa00c4fff [ 240.436669] [] ? i5000_init+0x2d/0x1000 [i5000_edac] [ 240.436673] [] ? do_one_initcall+0x74/0x106 [ 240.436677] [] ? load_module+0x127a/0x1dfc [ 240.436681] [] ? store_uevent+0x32/0x32 [ 240.436686] [] ? SyS_init_module+0x9c/0xa9 [ 240.436690] [] ? system_call_fastpath+0x16/0x1b [ 240.436696] INFO: task modprobe:566 blocked for more than 120 seconds. [ 240.436754] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 240.436813] modprobe D ffff88013fd93fc0 0 566 553 0x00000004 [ 240.436817] ffff88013961c870 0000000000000082 0000000000013fc0 ffff880139739fd8 [ 240.436821] ffff880139739fd8 ffff88013961c870 ffff880139739b88 ffffffffa02522f4 [ 240.436825] ffffffffa02522f0 0000000000000000 ffffffffa02522f8 ffffffff8137c77a [ 240.436829] Call Trace: [ 240.436835] [] ? schedule_preempt_disabled+0x5/0x6 [ 240.436839] [] ? __mutex_lock_common.isra.9+0x152/0x1e2 [ 240.436844] [] ? mutex_lock+0x16/0x25 [ 240.436851] [] ? i2c_register_adapter+0x259/0x284 [i2c_core] [ 240.436858] [] ? i801_probe+0x306/0x3f3 [i2c_i801] [ 240.436863] [] ? _raw_spin_unlock_irqrestore+0xc/0xd [ 240.436868] [] ? __pm_runtime_resume+0x5d/0x69 [ 240.436874] [] ? local_pci_probe+0x33/0x58 [ 240.436877] [] ? pci_device_probe+0xba/0xde [ 240.436882] [] ? driver_probe_device+0x92/0x1b3 [ 240.436886] [] ? __driver_attach+0x53/0x73 [ 240.436890] [] ? __device_attach+0x31/0x31 [ 240.436894] [] ? bus_for_each_dev+0x6b/0x75 [ 240.436898] [] ? bus_add_driver+0xeb/0x1f0 [ 240.436902] [] ? driver_register+0x82/0xeb [ 240.436907] [] ? 0xffffffffa01fbfff [ 240.436912] [] ? i2c_i801_init+0xab/0x1000 [i2c_i801] [ 240.436917] [] ? 0xffffffffa01fbfff [ 240.436920] [] ? do_one_initcall+0x74/0x106 [ 240.436925] [] ? load_module+0x127a/0x1dfc [ 240.436929] [] ? store_uevent+0x32/0x32 [ 240.436934] [] ? SyS_init_module+0x9c/0xa9 [ 240.436938] [] ? system_call_fastpath+0x16/0x1b [ 240.436945] INFO: task modprobe:598 blocked for more than 120 seconds. [ 240.437002] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 240.437061] modprobe D ffff8801387e1080 0 598 584 0x00000004 [ 240.437065] ffff8801387e1080 0000000000000086 0000000000013fc0 ffff880137dfdfd8 [ 240.437069] ffff880137dfdfd8 ffff880138911400 0000000000000000 ffff880138911790 [ 240.437073] 0000000000000000 0000000000000000 0000000000000000 ffffffffa01ef2f5 [ 240.437077] Call Trace: [ 240.437083] [] ? i801_transaction+0xa1/0xe4 [i2c_i801] [ 240.437089] [] ? finish_wait+0x60/0x60 [ 240.437094] [] ? i801_access+0x6d3/0x876 [i2c_i801] [ 240.437099] [] ? _raw_spin_unlock_irqrestore+0xc/0xd [ 240.437105] [] ? ep_poll_callback+0xde/0xf7 [ 240.437111] [] ? i2c_smbus_xfer+0xcb/0x121 [i2c_core] [ 240.437117] [] ? i2c_default_probe+0x95/0xf7 [i2c_core] [ 240.437123] [] ? i2c_do_add_adapter+0x11f/0x1fe [i2c_core] [ 240.437128] [] ? kfree+0x3a/0x6d [ 240.437134] [] ? kobject_uevent_env+0x3d7/0x40f [ 240.437140] [] ? __process_new_adapter+0x9/0x9 [i2c_core] [ 240.437144] [] ? bus_for_each_dev+0x6b/0x75 [ 240.437150] [] ? __process_new_adapter+0x9/0x9 [i2c_core] [ 240.437155] [] ? i2c_for_each_dev+0x2a/0x43 [i2c_core] [ 240.437161] [] ? i2c_register_driver+0x95/0x99 [i2c_core] [ 240.437165] [] ? 0xffffffffa0031fff [ 240.437169] [] ? do_one_initcall+0x74/0x106 [ 240.437174] [] ? load_module+0x127a/0x1dfc [ 240.437177] [] ? store_uevent+0x32/0x32 [ 240.437182] [] ? SyS_init_module+0x9c/0xa9 [ 240.437186] [] ? system_call_fastpath+0x16/0x1b [ 240.437190] INFO: task modprobe:627 blocked for more than 120 seconds. [ 240.437247] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 240.437307] modprobe D ffff88013fd53fc0 0 627 622 0x00000006 [ 240.437310] ffff8801389067b0 0000000000000082 0000000000013fc0 ffff880137e9ffd8 [ 240.437315] ffff880137e9ffd8 ffff8801389067b0 ffff880137e9fa48 ffffffffa02522f4 [ 240.437319] ffffffffa02522f0 0000000000000000 ffffffffa02522f8 ffffffff8137c77a [ 240.437323] Call Trace: [ 240.437329] [] ? schedule_preempt_disabled+0x5/0x6 [ 240.437333] [] ? __mutex_lock_common.isra.9+0x152/0x1e2 [ 240.437339] [] ? i2c_register_adapter+0x284/0x284 [i2c_core] [ 240.437343] [] ? mutex_lock+0x16/0x25 [ 240.437349] [] ? i2c_add_adapter+0x11/0x5b [i2c_core] [ 240.437354] [] ? __i2c_bit_add_bus+0x33/0x284 [i2c_algo_bit] [ 240.437397] [] ? radeon_i2c_create+0x1be/0x1f3 [radeon] [ 240.437427] [] ? radeon_combios_i2c_init+0x5e/0x215 [radeon] [ 240.437461] [] ? radeon_modeset_init+0x1fe/0x8f8 [radeon] [ 240.437487] [] ? radeon_debugfs_add_files+0xc2/0xc9 [radeon] [ 240.437515] [] ? radeon_driver_load_kms+0xb2/0xf8 [radeon] [ 240.437527] [] ? drm_get_pci_dev+0x152/0x262 [drm] [ 240.437531] [] ? kfree+0x3a/0x6d [ 240.437535] [] ? local_pci_probe+0x33/0x58 [ 240.437539] [] ? pci_device_probe+0xba/0xde [ 240.437543] [] ? driver_probe_device+0x92/0x1b3 [ 240.437547] [] ? __driver_attach+0x53/0x73 [ 240.437550] [] ? __device_attach+0x31/0x31 [ 240.437554] [] ? bus_for_each_dev+0x6b/0x75 [ 240.437559] [] ? bus_add_driver+0xeb/0x1f0 [ 240.437562] [] ? driver_register+0x82/0xeb [ 240.437566] [] ? 0xffffffffa0523fff [ 240.437570] [] ? do_one_initcall+0x74/0x106 [ 240.437574] [] ? load_module+0x127a/0x1dfc [ 240.437578] [] ? store_uevent+0x32/0x32 [ 240.437583] [] ? SyS_init_module+0x9c/0xa9 [ 240.437587] [] ? system_call_fastpath+0x16/0x1b Since I had to update my pxe setup, I updated to the latest debian netboot image, and a newer base install, which came with a 3.2 kernel which doesn't appear to have this issue. > Thanks. -- Thomas Fjellstrom tfjellstrom@strangesoft.net -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/