From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1759142Ab3GZOsB (ORCPT ); Fri, 26 Jul 2013 10:48:01 -0400 Received: from mail.tomasu.net ([64.85.170.232]:50992 "EHLO mail.tomasu.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1757231Ab3GZOr7 (ORCPT ); Fri, 26 Jul 2013 10:47:59 -0400 From: Thomas Fjellstrom To: LKML Subject: Re: hung task with 3.9.8/3.10.1 Date: Fri, 26 Jul 2013 08:47:12 -0600 Message-ID: <12175148.xrZ9MEMONN@balsa> User-Agent: KMail/4.10.5 (Linux/3.9-1-amd64; KDE/4.10.5; x86_64; ; ) In-Reply-To: <31240603.zcuBEB4roc@balsa> References: <137450198.fYZy8Ria9U@balsa> <31240603.zcuBEB4roc@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 On Sat 20 July 2013 17:19:30 Thomas Fjellstrom wrote: > 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-[797 > > 9 > > 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. I'm kind of stuck here. Should I try a bisect over 8 major kernel versions? Is there a known fix for this that I am unaware of? -- Thomas Fjellstrom tfjellstrom@strangesoft.net