task kworker/1:0:9 blocked for more than 120 seconds after resume

"nai.xia" <[email protected]> Tue, 20 Mar 2012 09:30:21 +0800
Newsgroups gmane.linux.swsusp.devel
Message-ID <[email protected]>
Hi all,


Today I tried tuxonice 3.2.1 (I got from git and merged it with ubuntu's 3.2 kernel).
Tuxonice can hibernate easily, but after it resumes, I saw this:

---
Mar 20 09:06:44 raynor kernel: [  182.064578] TuxOnIce debugging info:
Mar 20 09:06:44 raynor kernel: [  182.064578] - TuxOnIce core  : 3.2.1
Mar 20 09:06:44 raynor kernel: [  182.064578] - Kernel Version : 3.2.0-19-generic-tuxonice
Mar 20 09:06:44 raynor kernel: [  182.064579] - Compiler vers. : 4.6
Mar 20 09:06:44 raynor kernel: [  182.064579] - Attempt number : 1
Mar 20 09:06:44 raynor kernel: [  182.064579] - Parameters     : 0 667656 0 1 -2 5
Mar 20 09:06:44 raynor kernel: [  182.064580] - Overall expected compression percentage: 0.
Mar 20 09:06:44 raynor kernel: [  182.064580] - Checksum method is 'md4'.
Mar 20 09:06:44 raynor kernel: [  182.064580]   0 pages resaved in atomic copy.
Mar 20 09:06:44 raynor kernel: [  182.064581] - Compressor is 'lzo'.
Mar 20 09:06:44 raynor kernel: [  182.064581]   Compressed 1007841280 bytes into 349281655 (65 percent compression).
Mar 20 09:06:44 raynor kernel: [  182.064582] - Block I/O active.
Mar 20 09:06:44 raynor kernel: [  182.064582]   Used 86209 pages from swap on /dev/sdb3.
Mar 20 09:06:44 raynor kernel: [  182.064582] - Max outstanding reads 1268. Max writes 17288.
Mar 20 09:06:44 raynor kernel: [  182.064583]   Memory_needed: 1024 x (4096 + 368 + 112) = 4685824 bytes.
Mar 20 09:06:44 raynor kernel: [  182.064583]   Free mem throttle point reached 0.
Mar 20 09:06:44 raynor kernel: [  182.064583] - Swap Allocator enabled.
Mar 20 09:06:44 raynor kernel: [  182.064584]   Swap available for image: 12207030 pages.
Mar 20 09:06:44 raynor kernel: [  182.064584] - File Allocator active.
Mar 20 09:06:44 raynor kernel: [  182.064584]   Storage available for image: 0 pages.
Mar 20 09:06:44 raynor kernel: [  182.064585] - I/O speed: Write 259 MB/s, Read 238 MB/s.
Mar 20 09:06:44 raynor kernel: [  182.064585] - Extra pages    : 0 used/2000.
Mar 20 09:06:44 raynor kernel: [  182.064586] - Result         : Succeeded.
Mar 20 09:06:45 raynor kernel: [  182.559587] r8169 0000:04:00.0: eth0: link up
Mar 20 09:09:43 raynor kernel: [  360.849233] INFO: task kworker/1:0:9 blocked for more than 120 seconds.
Mar 20 09:09:43 raynor kernel: [  360.849554] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 20 09:09:43 raynor kernel: [  360.849890] kworker/1:0     D ffffffff81806240     0     9      2 0x00000000
Mar 20 09:09:43 raynor kernel: [  360.849892]  ffff880425f3dab0 0000000000000046 ffff880425f344e8 0000000000000001
Mar 20 09:09:43 raynor kernel: [  360.849895]  ffff880425f3dfd8 ffff880425f3dfd8 ffff880425f3dfd8 0000000000013840
Mar 20 09:09:43 raynor kernel: [  360.849896]  ffff880425fc96e0 ffff880425f344a0 ffff880425f3da90 ffff88041d42aa90
Mar 20 09:09:43 raynor kernel: [  360.849898] Call Trace:
Mar 20 09:09:43 raynor kernel: [  360.849903]  [<ffffffff8167609f>] schedule+0x3f/0x60
Mar 20 09:09:43 raynor kernel: [  360.849905]  [<ffffffff81676ea7>] __mutex_lock_slowpath+0xd7/0x150
Mar 20 09:09:43 raynor kernel: [  360.849907]  [<ffffffff81676aba>] mutex_lock+0x2a/0x50
Mar 20 09:09:43 raynor kernel: [  360.849909]  [<ffffffff8112e3b6>] generic_file_aio_write+0x56/0xe0
Mar 20 09:09:43 raynor kernel: [  360.849911]  [<ffffffff8167609f>] ? schedule+0x3f/0x60
Mar 20 09:09:43 raynor kernel: [  360.849913]  [<ffffffff81225edf>] ext4_file_write+0xbf/0x260
Mar 20 09:09:43 raynor kernel: [  360.849915]  [<ffffffff8103dbb9>] ? default_spin_lock_flags+0x9/0x10
Mar 20 09:09:43 raynor kernel: [  360.849916]  [<ffffffff8167823e>] ? _raw_spin_lock_irqsave+0x2e/0x40
Mar 20 09:09:43 raynor kernel: [  360.849919]  [<ffffffff8118c572>] do_sync_write+0xd2/0x110
Mar 20 09:09:43 raynor kernel: [  360.849920]  [<ffffffff81052012>] ? ttwu_queue+0x92/0xd0
Mar 20 09:09:43 raynor kernel: [  360.849922]  [<ffffffff8105fa4e>] ? try_to_wake_up+0x18e/0x200
Mar 20 09:09:43 raynor kernel: [  360.849924]  [<ffffffff8101a779>] ? read_tsc+0x9/0x20
Mar 20 09:09:43 raynor kernel: [  360.849926]  [<ffffffff81094fad>] ? ktime_get_ts+0xad/0xe0
Mar 20 09:09:43 raynor kernel: [  360.849928]  [<ffffffff810c78f4>] do_acct_process+0x2f4/0x350
Mar 20 09:09:43 raynor kernel: [  360.849929]  [<ffffffff810c79b6>] acct_process_in_ns+0x66/0x90
Mar 20 09:09:43 raynor kernel: [  360.849930]  [<ffffffff810c80c0>] acct_process+0x30/0x50
Mar 20 09:09:43 raynor kernel: [  360.849932]  [<ffffffff8106bc76>] do_exit+0x2c6/0x420
Mar 20 09:09:43 raynor kernel: [  360.849935]  [<ffffffff810859e0>] ? manage_workers.isra.29+0x130/0x130
Mar 20 09:09:43 raynor kernel: [  360.849936]  [<ffffffff8108a396>] kthread+0x86/0xa0
Mar 20 09:09:43 raynor kernel: [  360.849938]  [<ffffffff81682734>] kernel_thread_helper+0x4/0x10
Mar 20 09:09:43 raynor kernel: [  360.849940]  [<ffffffff8108a310>] ? flush_kthread_worker+0xa0/0xa0
Mar 20 09:09:43 raynor kernel: [  360.849941]  [<ffffffff81682730>] ? gs_change+0x13/0x13
Mar 20 09:09:43 raynor kernel: [  360.849942] INFO: task migration/2:13 blocked for more than 120 seconds.
Mar 20 09:09:43 raynor kernel: [  360.850287] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 20 09:09:43 raynor kernel: [  360.850643] migration/2     D 0000000000000000     0    13      2 0x00000000
Mar 20 09:09:43 raynor kernel: [  360.850645]  ffff880425fd3ab0 0000000000000046 0000000000000000 0000000000000000
Mar 20 09:09:43 raynor kernel: [  360.850647]  ffff880425fd3fd8 ffff880425fd3fd8 ffff880425fd3fd8 0000000000013840
Mar 20 09:09:43 raynor kernel: [  360.850649]  ffff880425fe2dc0 ffff880425fcc4a0 00000000000005fa ffff88041d42aa90
Mar 20 09:09:43 raynor kernel: [  360.850650] Call Trace:
Mar 20 09:09:43 raynor kernel: [  360.850652]  [<ffffffff8167609f>] schedule+0x3f/0x60
Mar 20 09:09:43 raynor kernel: [  360.850653]  [<ffffffff81676ea7>] __mutex_lock_slowpath+0xd7/0x150
Mar 20 09:09:43 raynor kernel: [  360.850656]  [<ffffffff81322db6>] ? cpumask_next_and+0x36/0x50
Mar 20 09:09:43 raynor kernel: [  360.850657]  [<ffffffff81676aba>] mutex_lock+0x2a/0x50
Mar 20 09:09:43 raynor kernel: [  360.850659]  [<ffffffff8112e3b6>] generic_file_aio_write+0x56/0xe0
Mar 20 09:09:43 raynor kernel: [  360.850660]  [<ffffffff81225edf>] ext4_file_write+0xbf/0x260
Mar 20 09:09:43 raynor kernel: [  360.850663]  [<ffffffff81033b44>] ? __assign_irq_vector+0x234/0x290
Mar 20 09:09:43 raynor kernel: [  360.850664]  [<ffffffff81033b44>] ? __assign_irq_vector+0x234/0x290
Mar 20 09:09:43 raynor kernel: [  360.850666]  [<ffffffff8118c572>] do_sync_write+0xd2/0x110
Mar 20 09:09:43 raynor kernel: [  360.850667]  [<ffffffff81090ffd>] ? sched_clock_cpu+0xbd/0x110
Mar 20 09:09:43 raynor kernel: [  360.850669]  [<ffffffff810126e5>] ? __switch_to+0xf5/0x360
Mar 20 09:09:43 raynor kernel: [  360.850671]  [<ffffffff81677fae>] ? _raw_spin_lock+0xe/0x20
Mar 20 09:09:43 raynor kernel: [  360.850672]  [<ffffffff8101a779>] ? read_tsc+0x9/0x20
Mar 20 09:09:43 raynor kernel: [  360.850673]  [<ffffffff81094fad>] ? ktime_get_ts+0xad/0xe0
Mar 20 09:09:43 raynor kernel: [  360.850674]  [<ffffffff810c78f4>] do_acct_process+0x2f4/0x350
Mar 20 09:09:43 raynor kernel: [  360.850676]  [<ffffffff810d6801>] ? queue_stop_cpus_work+0x51/0xd0
Mar 20 09:09:43 raynor kernel: [  360.850677]  [<ffffffff810c79b6>] acct_process_in_ns+0x66/0x90
Mar 20 09:09:43 raynor kernel: [  360.850679]  [<ffffffff810c80c0>] acct_process+0x30/0x50
Mar 20 09:09:43 raynor kernel: [  360.850680]  [<ffffffff8106bc76>] do_exit+0x2c6/0x420
Mar 20 09:09:43 raynor kernel: [  360.850681]  [<ffffffff810d69f0>] ? __stop_cpus+0x80/0x80
Mar 20 09:09:43 raynor kernel: [  360.850683]  [<ffffffff8108a396>] kthread+0x86/0xa0
Mar 20 09:09:43 raynor kernel: [  360.850684]  [<ffffffff81682734>] kernel_thread_helper+0x4/0x10
Mar 20 09:09:43 raynor kernel: [  360.850685]  [<ffffffff8108a310>] ? flush_kthread_worker+0xa0/0xa0
Mar 20 09:09:43 raynor kernel: [  360.850687]  [<ffffffff81682730>] ? gs_change+0x13/0x13
Mar 20 09:09:43 raynor kernel: [  360.850688] INFO: task kworker/2:0:14 blocked for more than 120 seconds.
Mar 20 09:09:43 raynor kernel: [  360.851057] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 20 09:09:43 raynor kernel: [  360.851438] kworker/2:0     D ffffffff81806240     0    14      2 0x00000000
Mar 20 09:09:43 raynor kernel: [  360.851439]  ffff880425fd9ab0 0000000000000046 ffff880425fcdbc8 0000000000000001
Mar 20 09:09:43 raynor kernel: [  360.851441]  ffff880425fd9fd8 ffff880425fd9fd8 ffff880425fd9fd8 0000000000013840
Mar 20 09:09:43 raynor kernel: [  360.851443]  ffff880425fe16e0 ffff880425fcdb80 0000000000000000 ffff88041d42aa90
Mar 20 09:09:43 raynor kernel: [  360.851445] Call Trace:
Mar 20 09:09:43 raynor kernel: [  360.851446]  [<ffffffff8167609f>] schedule+0x3f/0x60
Mar 20 09:09:43 raynor kernel: [  360.851448]  [<ffffffff81676ea7>] __mutex_lock_slowpath+0xd7/0x150
Mar 20 09:09:43 raynor kernel: [  360.851449]  [<ffffffff81676aba>] mutex_lock+0x2a/0x50
Mar 20 09:09:43 raynor kernel: [  360.851451]  [<ffffffff8112e3b6>] generic_file_aio_write+0x56/0xe0
Mar 20 09:09:43 raynor kernel: [  360.851452]  [<ffffffff8167609f>] ? schedule+0x3f/0x60
Mar 20 09:09:43 raynor kernel: [  360.851454]  [<ffffffff81225edf>] ext4_file_write+0xbf/0x260
Mar 20 09:09:43 raynor kernel: [  360.851455]  [<ffffffff8103dbb9>] ? default_spin_lock_flags+0x9/0x10
Mar 20 09:09:43 raynor kernel: [  360.851456]  [<ffffffff8167823e>] ? _raw_spin_lock_irqsave+0x2e/0x40
Mar 20 09:09:43 raynor kernel: [  360.851458]  [<ffffffff8118c572>] do_sync_write+0xd2/0x110
Mar 20 09:09:43 raynor kernel: [  360.851459]  [<ffffffff81052012>] ? ttwu_queue+0x92/0xd0
Mar 20 09:09:43 raynor kernel: [  360.851461]  [<ffffffff8105fa4e>] ? try_to_wake_up+0x18e/0x200
Mar 20 09:09:43 raynor kernel: [  360.851462]  [<ffffffff8101a779>] ? read_tsc+0x9/0x20
Mar 20 09:09:43 raynor kernel: [  360.851463]  [<ffffffff81094fad>] ? ktime_get_ts+0xad/0xe0
Mar 20 09:09:43 raynor kernel: [  360.851464]  [<ffffffff810c78f4>] do_acct_process+0x2f4/0x350
Mar 20 09:09:43 raynor kernel: [  360.851466]  [<ffffffff810c79b6>] acct_process_in_ns+0x66/0x90
Mar 20 09:09:43 raynor kernel: [  360.851467]  [<ffffffff810c80c0>] acct_process+0x30/0x50
Mar 20 09:09:43 raynor kernel: [  360.851468]  [<ffffffff8106bc76>] do_exit+0x2c6/0x420
Mar 20 09:09:43 raynor kernel: [  360.851470]  [<ffffffff810859e0>] ? manage_workers.isra.29+0x130/0x130
Mar 20 09:09:43 raynor kernel: [  360.851471]  [<ffffffff8108a396>] kthread+0x86/0xa0
Mar 20 09:09:43 raynor kernel: [  360.851473]  [<ffffffff81682734>] kernel_thread_helper+0x4/0x10
Mar 20 09:09:43 raynor kernel: [  360.851474]  [<ffffffff8108a310>] ? flush_kthread_worker+0xa0/0xa0
Mar 20 09:09:43 raynor kernel: [  360.851476]  [<ffffffff81682730>] ? gs_change+0x13/0x13
Mar 20 09:09:43 raynor kernel: [  360.851477] INFO: task watchdog/2:16 blocked for more than 120 seconds.
Mar 20 09:09:43 raynor kernel: [  360.851865] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 20 09:09:43 raynor kernel: [  360.852267] watchdog/2      D 0000000000000000     0    16      2 0x00000000
Mar 20 09:09:43 raynor kernel: [  360.852269]  ffff880425febab0 0000000000000046 ffff880402618000 ffff88043fa13840
Mar 20 09:09:43 raynor kernel: [  360.852271]  ffff880425febfd8 ffff880425febfd8 ffff880425febfd8 0000000000013840
Mar 20 09:09:43 raynor kernel: [  360.852272]  ffff880402618000 ffff880425fe2dc0 ffff880425febb00 ffff88041d42aa90
Mar 20 09:09:43 raynor kernel: [  360.852274] Call Trace:
Mar 20 09:09:43 raynor kernel: [  360.852276]  [<ffffffff8167609f>] schedule+0x3f/0x60
Mar 20 09:09:43 raynor kernel: [  360.852277]  [<ffffffff81676ea7>] __mutex_lock_slowpath+0xd7/0x150
Mar 20 09:09:43 raynor kernel: [  360.852279]  [<ffffffff81676aba>] mutex_lock+0x2a/0x50
Mar 20 09:09:43 raynor kernel: [  360.852280]  [<ffffffff8112e3b6>] generic_file_aio_write+0x56/0xe0
Mar 20 09:09:43 raynor kernel: [  360.852281]  [<ffffffff81322db6>] ? cpumask_next_and+0x36/0x50
Mar 20 09:09:43 raynor kernel: [  360.852283]  [<ffffffff81225edf>] ext4_file_write+0xbf/0x260
Mar 20 09:09:43 raynor kernel: [  360.852285]  [<ffffffff8118c572>] do_sync_write+0xd2/0x110
Mar 20 09:09:43 raynor kernel: [  360.852286]  [<ffffffff8101a779>] ? read_tsc+0x9/0x20
Mar 20 09:09:43 raynor kernel: [  360.852287]  [<ffffffff81094fad>] ? ktime_get_ts+0xad/0xe0
Mar 20 09:09:43 raynor kernel: [  360.852288]  [<ffffffff810c78f4>] do_acct_process+0x2f4/0x350
Mar 20 09:09:43 raynor kernel: [  360.852290]  [<ffffffff810c79b6>] acct_process_in_ns+0x66/0x90
Mar 20 09:09:43 raynor kernel: [  360.852291]  [<ffffffff810c80c0>] acct_process+0x30/0x50
Mar 20 09:09:43 raynor kernel: [  360.852292]  [<ffffffff8106bc76>] do_exit+0x2c6/0x420
Mar 20 09:09:43 raynor kernel: [  360.852294]  [<ffffffff810619c3>] ? sched_setscheduler+0x13/0x20
Mar 20 09:09:43 raynor kernel: [  360.852296]  [<ffffffff810ed650>] ? watchdog_enable+0x100/0x100
Mar 20 09:09:43 raynor kernel: [  360.852297]  [<ffffffff8108a396>] kthread+0x86/0xa0
Mar 20 09:09:43 raynor kernel: [  360.852299]  [<ffffffff81682734>] kernel_thread_helper+0x4/0x10
Mar 20 09:09:43 raynor kernel: [  360.852300]  [<ffffffff8108a310>] ? flush_kthread_worker+0xa0/0xa0
Mar 20 09:09:43 raynor kernel: [  360.852301]  [<ffffffff81682730>] ? gs_change+0x13/0x13
Mar 20 09:09:43 raynor kernel: [  360.852302] INFO: task migration/3:17 blocked for more than 120 seconds.
Mar 20 09:09:43 raynor kernel: [  360.852715] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 20 09:09:43 raynor kernel: [  360.853146] migration/3     D 0000000000000000     0    17      2 0x00000000
Mar 20 09:09:43 raynor kernel: [  360.853147]  ffff880425fedab0 0000000000000046 0000000000000000 0000000000000000
Mar 20 09:09:43 raynor kernel: [  360.853149]  ffff880425fedfd8 ffff880425fedfd8 ffff880425fedfd8 0000000000013840
Mar 20 09:09:43 raynor kernel: [  360.853151]  ffff880425802dc0 ffff880425fe44a0 0000000000000438 ffff88041d42aa90
Mar 20 09:09:43 raynor kernel: [  360.853153] Call Trace:
Mar 20 09:09:43 raynor kernel: [  360.853154]  [<ffffffff8167609f>] schedule+0x3f/0x60
Mar 20 09:09:43 raynor kernel: [  360.853156]  [<ffffffff81676ea7>] __mutex_lock_slowpath+0xd7/0x150
Mar 20 09:09:43 raynor kernel: [  360.853157]  [<ffffffff81322db6>] ? cpumask_next_and+0x36/0x50
Mar 20 09:09:43 raynor kernel: [  360.853159]  [<ffffffff81676aba>] mutex_lock+0x2a/0x50
Mar 20 09:09:43 raynor kernel: [  360.853160]  [<ffffffff8112e3b6>] generic_file_aio_write+0x56/0xe0
Mar 20 09:09:43 raynor kernel: [  360.853162]  [<ffffffff81225edf>] ext4_file_write+0xbf/0x260
Mar 20 09:09:43 raynor kernel: [  360.853163]  [<ffffffff81033b44>] ? __assign_irq_vector+0x234/0x290
Mar 20 09:09:43 raynor kernel: [  360.853165]  [<ffffffff81033b44>] ? __assign_irq_vector+0x234/0x290
Mar 20 09:09:43 raynor kernel: [  360.853166]  [<ffffffff8118c572>] do_sync_write+0xd2/0x110
Mar 20 09:09:43 raynor kernel: [  360.853168]  [<ffffffff81090ffd>] ? sched_clock_cpu+0xbd/0x110
Mar 20 09:09:43 raynor kernel: [  360.853169]  [<ffffffff810126e5>] ? __switch_to+0xf5/0x360
Mar 20 09:09:43 raynor kernel: [  360.853171]  [<ffffffff81677fae>] ? _raw_spin_lock+0xe/0x20
Mar 20 09:09:43 raynor kernel: [  360.853172]  [<ffffffff8101a779>] ? read_tsc+0x9/0x20
Mar 20 09:09:43 raynor kernel: [  360.853174]  [<ffffffff81094fad>] ? ktime_get_ts+0xad/0xe0
Mar 20 09:09:43 raynor kernel: [  360.853176]  [<ffffffff810c78f4>] do_acct_process+0x2f4/0x350
Mar 20 09:09:43 raynor kernel: [  360.853178]  [<ffffffff810d6801>] ? queue_stop_cpus_work+0x51/0xd0
Mar 20 09:09:43 raynor kernel: [  360.853181]  [<ffffffff810c79b6>] acct_process_in_ns+0x66/0x90
Mar 20 09:09:43 raynor kernel: [  360.853183]  [<ffffffff810c80c0>] acct_process+0x30/0x50
Mar 20 09:09:43 raynor kernel: [  360.853185]  [<ffffffff8106bc76>] do_exit+0x2c6/0x420
Mar 20 09:09:43 raynor kernel: [  360.853187]  [<ffffffff810d69f0>] ? __stop_cpus+0x80/0x80
Mar 20 09:09:43 raynor kernel: [  360.853189]  [<ffffffff8108a396>] kthread+0x86/0xa0
Mar 20 09:09:43 raynor kernel: [  360.853192]  [<ffffffff81682734>] kernel_thread_helper+0x4/0x10
Mar 20 09:09:43 raynor kernel: [  360.853194]  [<ffffffff8108a310>] ? flush_kthread_worker+0xa0/0xa0
Mar 20 09:09:43 raynor kernel: [  360.853196]  [<ffffffff81682730>] ? gs_change+0x13/0x13
Mar 20 09:09:43 raynor kernel: [  360.853198] INFO: task kworker/3:0:18 blocked for more than 120 seconds.
Mar 20 09:09:43 raynor kernel: [  360.853635] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 20 09:09:43 raynor kernel: [  360.854085] kworker/3:0     D ffffffff81806240     0    18      2 0x00000000
Mar 20 09:09:43 raynor kernel: [  360.854086]  ffff880425fefab0 0000000000000046 ffff880425fe5bc8 0000000000000001
Mar 20 09:09:43 raynor kernel: [  360.854088]  ffff880425feffd8 ffff880425feffd8 ffff880425feffd8 0000000000013840
Mar 20 09:09:43 raynor kernel: [  360.854090]  ffff8804258016e0 ffff880425fe5b80 0000000000000000 ffff88041d42aa90
Mar 20 09:09:43 raynor kernel: [  360.854092] Call Trace:
Mar 20 09:09:43 raynor kernel: [  360.854093]  [<ffffffff8167609f>] schedule+0x3f/0x60
Mar 20 09:09:43 raynor kernel: [  360.854095]  [<ffffffff81676ea7>] __mutex_lock_slowpath+0xd7/0x150
Mar 20 09:09:43 raynor kernel: [  360.854097]  [<ffffffff8104ddb2>] ? complete+0x52/0x60
Mar 20 09:09:43 raynor kernel: [  360.854098]  [<ffffffff81676aba>] mutex_lock+0x2a/0x50
Mar 20 09:09:43 raynor kernel: [  360.854099]  [<ffffffff8112e3b6>] generic_file_aio_write+0x56/0xe0
Mar 20 09:09:43 raynor kernel: [  360.854101]  [<ffffffff811772ab>] ? kfree+0x3b/0x140
Mar 20 09:09:43 raynor kernel: [  360.854103]  [<ffffffff814af640>] ? usb_free_urb+0x20/0x20
Mar 20 09:09:43 raynor kernel: [  360.854104]  [<ffffffff81225edf>] ext4_file_write+0xbf/0x260
Mar 20 09:09:43 raynor kernel: [  360.854106]  [<ffffffff81326146>] ? kref_put+0x36/0x70
Mar 20 09:09:43 raynor kernel: [  360.854108]  [<ffffffff814af63a>] ? usb_free_urb+0x1a/0x20
Mar 20 09:09:43 raynor kernel: [  360.854109]  [<ffffffff814b06b0>] ? usb_start_wait_urb+0xa0/0xf0
Mar 20 09:09:43 raynor kernel: [  360.854111]  [<ffffffff8118c572>] do_sync_write+0xd2/0x110
Mar 20 09:09:43 raynor kernel: [  360.854113]  [<ffffffff810772a8>] ? lock_timer_base.isra.29+0x38/0x70
Mar 20 09:09:43 raynor kernel: [  360.854114]  [<ffffffff81052012>] ? ttwu_queue+0x92/0xd0
Mar 20 09:09:43 raynor kernel: [  360.854116]  [<ffffffff8105fa4e>] ? try_to_wake_up+0x18e/0x200
Mar 20 09:09:43 raynor kernel: [  360.854117]  [<ffffffff8101a779>] ? read_tsc+0x9/0x20
Mar 20 09:09:43 raynor kernel: [  360.854118]  [<ffffffff81094fad>] ? ktime_get_ts+0xad/0xe0
Mar 20 09:09:43 raynor kernel: [  360.854119]  [<ffffffff810c78f4>] do_acct_process+0x2f4/0x350
Mar 20 09:09:43 raynor kernel: [  360.854121]  [<ffffffff810c79b6>] acct_process_in_ns+0x66/0x90
Mar 20 09:09:43 raynor kernel: [  360.854122]  [<ffffffff810c80c0>] acct_process+0x30/0x50
Mar 20 09:09:43 raynor kernel: [  360.854123]  [<ffffffff8106bc76>] do_exit+0x2c6/0x420
Mar 20 09:09:43 raynor kernel: [  360.854125]  [<ffffffff810859e0>] ? manage_workers.isra.29+0x130/0x130
Mar 20 09:09:43 raynor kernel: [  360.854126]  [<ffffffff8108a396>] kthread+0x86/0xa0
Mar 20 09:09:43 raynor kernel: [  360.854128]  [<ffffffff81682734>] kernel_thread_helper+0x4/0x10
Mar 20 09:09:43 raynor kernel: [  360.854129]  [<ffffffff8108a310>] ? flush_kthread_worker+0xa0/0xa0
Mar 20 09:09:43 raynor kernel: [  360.854130]  [<ffffffff81682730>] ? gs_change+0x13/0x13
Mar 20 09:09:43 raynor kernel: [  360.854131] INFO: task ksoftirqd/3:19 blocked for more than 120 seconds.
Mar 20 09:09:43 raynor kernel: [  360.854589] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 20 09:09:43 raynor kernel: [  360.855062] ksoftirqd/3     D 0000000000000000     0    19      2 0x00000000
Mar 20 09:09:43 raynor kernel: [  360.855063]  ffff880425ffdab0 0000000000000046 0b294557d0a8056f c965c1ced9e8c5f3
Mar 20 09:09:43 raynor kernel: [  360.855065]  ffff880425ffdfd8 ffff880425ffdfd8 ffff880425ffdfd8 0000000000013840
Mar 20 09:09:43 raynor kernel: [  360.855067]  ffff880402618000 ffff880425800000 0000000000000001 ffff88041d42aa90
Mar 20 09:09:43 raynor kernel: [  360.855069] Call Trace:
Mar 20 09:09:43 raynor kernel: [  360.855070]  [<ffffffff8167609f>] schedule+0x3f/0x60
Mar 20 09:09:43 raynor kernel: [  360.855072]  [<ffffffff81676ea7>] __mutex_lock_slowpath+0xd7/0x150
Mar 20 09:09:43 raynor kernel: [  360.855073]  [<ffffffff81676aba>] mutex_lock+0x2a/0x50
Mar 20 09:09:43 raynor kernel: [  360.855075]  [<ffffffff8112e3b6>] generic_file_aio_write+0x56/0xe0
Mar 20 09:09:43 raynor kernel: [  360.855076]  [<ffffffff81322db6>] ? cpumask_next_and+0x36/0x50
Mar 20 09:09:43 raynor kernel: [  360.855077]  [<ffffffff8105a5a1>] ? find_busiest_group+0x171/0xbb0
Mar 20 09:09:43 raynor kernel: [  360.855079]  [<ffffffff81225edf>] ext4_file_write+0xbf/0x260
Mar 20 09:09:43 raynor kernel: [  360.855081]  [<ffffffff8118c572>] do_sync_write+0xd2/0x110
Mar 20 09:09:43 raynor kernel: [  360.855082]  [<ffffffff8101a779>] ? read_tsc+0x9/0x20
Mar 20 09:09:43 raynor kernel: [  360.855083]  [<ffffffff81094fad>] ? ktime_get_ts+0xad/0xe0
Mar 20 09:09:43 raynor kernel: [  360.855084]  [<ffffffff810c78f4>] do_acct_process+0x2f4/0x350
Mar 20 09:09:43 raynor kernel: [  360.855086]  [<ffffffff810c79b6>] acct_process_in_ns+0x66/0x90
Mar 20 09:09:43 raynor kernel: [  360.855087]  [<ffffffff810c80c0>] acct_process+0x30/0x50
Mar 20 09:09:43 raynor kernel: [  360.855088]  [<ffffffff8106bc76>] do_exit+0x2c6/0x420
Mar 20 09:09:43 raynor kernel: [  360.855090]  [<ffffffff8167609f>] ? schedule+0x3f/0x60
Mar 20 09:09:43 raynor kernel: [  360.855092]  [<ffffffff8106ec95>] ? run_ksoftirqd+0xe5/0x170
Mar 20 09:09:43 raynor kernel: [  360.855093]  [<ffffffff8106ebb0>] ? __do_softirq+0x210/0x210
Mar 20 09:09:43 raynor kernel: [  360.855094]  [<ffffffff8108a396>] kthread+0x86/0xa0
Mar 20 09:09:43 raynor kernel: [  360.855096]  [<ffffffff81682734>] kernel_thread_helper+0x4/0x10
Mar 20 09:09:43 raynor kernel: [  360.855097]  [<ffffffff8108a310>] ? flush_kthread_worker+0xa0/0xa0
Mar 20 09:09:43 raynor kernel: [  360.855099]  [<ffffffff81682730>] ? gs_change+0x13/0x13
Mar 20 09:09:43 raynor kernel: [  360.855100] INFO: task watchdog/3:20 blocked for more than 120 seconds.
Mar 20 09:09:43 raynor kernel: [  360.855580] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 20 09:09:43 raynor kernel: [  360.856075] watchdog/3      D 0000000000000000     0    20      2 0x00000000
Mar 20 09:09:43 raynor kernel: [  360.856076]  ffff880425809ab0 0000000000000046 ffff880402618000 ffff88043fa13840
Mar 20 09:09:43 raynor kernel: [  360.856078]  ffff880425809fd8 ffff880425809fd8 ffff880425809fd8 0000000000013840
Mar 20 09:09:43 raynor kernel: [  360.856080]  ffff880402618000 ffff880425802dc0 ffff880425809b00 ffff88041d42aa90
Mar 20 09:09:43 raynor kernel: [  360.856082] Call Trace:
Mar 20 09:09:43 raynor kernel: [  360.856083]  [<ffffffff8167609f>] schedule+0x3f/0x60
Mar 20 09:09:43 raynor kernel: [  360.856085]  [<ffffffff81676ea7>] __mutex_lock_slowpath+0xd7/0x150
Mar 20 09:09:43 raynor kernel: [  360.856086]  [<ffffffff81676aba>] mutex_lock+0x2a/0x50
Mar 20 09:09:43 raynor kernel: [  360.856088]  [<ffffffff8112e3b6>] generic_file_aio_write+0x56/0xe0
Mar 20 09:09:43 raynor kernel: [  360.856089]  [<ffffffff81322db6>] ? cpumask_next_and+0x36/0x50
Mar 20 09:09:43 raynor kernel: [  360.856090]  [<ffffffff81225edf>] ext4_file_write+0xbf/0x260
Mar 20 09:09:43 raynor kernel: [  360.856092]  [<ffffffff8118c572>] do_sync_write+0xd2/0x110
Mar 20 09:09:43 raynor kernel: [  360.856093]  [<ffffffff8101a779>] ? read_tsc+0x9/0x20
Mar 20 09:09:43 raynor kernel: [  360.856095]  [<ffffffff81094fad>] ? ktime_get_ts+0xad/0xe0
Mar 20 09:09:43 raynor kernel: [  360.856096]  [<ffffffff810c78f4>] do_acct_process+0x2f4/0x350
Mar 20 09:09:43 raynor kernel: [  360.856097]  [<ffffffff810c79b6>] acct_process_in_ns+0x66/0x90
Mar 20 09:09:43 raynor kernel: [  360.856098]  [<ffffffff810c80c0>] acct_process+0x30/0x50
Mar 20 09:09:43 raynor kernel: [  360.856100]  [<ffffffff8106bc76>] do_exit+0x2c6/0x420
Mar 20 09:09:43 raynor kernel: [  360.856101]  [<ffffffff810619c3>] ? sched_setscheduler+0x13/0x20
Mar 20 09:09:43 raynor kernel: [  360.856103]  [<ffffffff810ed650>] ? watchdog_enable+0x100/0x100
Mar 20 09:09:43 raynor kernel: [  360.856104]  [<ffffffff8108a396>] kthread+0x86/0xa0
Mar 20 09:09:43 raynor kernel: [  360.856105]  [<ffffffff81682734>] kernel_thread_helper+0x4/0x10
Mar 20 09:09:43 raynor kernel: [  360.856107]  [<ffffffff8108a310>] ? flush_kthread_worker+0xa0/0xa0
Mar 20 09:09:43 raynor kernel: [  360.856108]  [<ffffffff81682730>] ? gs_change+0x13/0x13
Mar 20 09:09:43 raynor kernel: [  360.856109] INFO: task migration/4:21 blocked for more than 120 seconds.
Mar 20 09:09:43 raynor kernel: [  360.856614] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 20 09:09:43 raynor kernel: [  360.857134] migration/4     D 0000000000000000     0    21      2 0x00000000
Mar 20 09:09:43 raynor kernel: [  360.857135]  ffff88042580bab0 0000000000000046 0000000000000000 0000000000000000
Mar 20 09:09:43 raynor kernel: [  360.857137]  ffff88042580bfd8 ffff88042580bfd8 ffff88042580bfd8 0000000000013840
Mar 20 09:09:43 raynor kernel: [  360.857139]  ffff88042581adc0 ffff8804258044a0 00000000000003fe ffff88041d42aa90
Mar 20 09:09:43 raynor kernel: [  360.857141] Call Trace:
Mar 20 09:09:43 raynor kernel: [  360.857142]  [<ffffffff8167609f>] schedule+0x3f/0x60
Mar 20 09:09:43 raynor kernel: [  360.857144]  [<ffffffff81676ea7>] __mutex_lock_slowpath+0xd7/0x150
Mar 20 09:09:43 raynor kernel: [  360.857145]  [<ffffffff81322db6>] ? cpumask_next_and+0x36/0x50
Mar 20 09:09:43 raynor kernel: [  360.857147]  [<ffffffff81676aba>] mutex_lock+0x2a/0x50
Mar 20 09:09:43 raynor kernel: [  360.857148]  [<ffffffff8112e3b6>] generic_file_aio_write+0x56/0xe0
Mar 20 09:09:43 raynor kernel: [  360.857150]  [<ffffffff81225edf>] ext4_file_write+0xbf/0x260
Mar 20 09:09:43 raynor kernel: [  360.857151]  [<ffffffff81033b44>] ? __assign_irq_vector+0x234/0x290
Mar 20 09:09:43 raynor kernel: [  360.857153]  [<ffffffff81033b44>] ? __assign_irq_vector+0x234/0x290
Mar 20 09:09:43 raynor kernel: [  360.857154]  [<ffffffff8118c572>] do_sync_write+0xd2/0x110
Mar 20 09:09:43 raynor kernel: [  360.857155]  [<ffffffff81090ffd>] ? sched_clock_cpu+0xbd/0x110
Mar 20 09:09:43 raynor kernel: [  360.857157]  [<ffffffff810126e5>] ? __switch_to+0xf5/0x360
Mar 20 09:09:43 raynor kernel: [  360.857159]  [<ffffffff81677fae>] ? _raw_spin_lock+0xe/0x20
Mar 20 09:09:43 raynor kernel: [  360.857160]  [<ffffffff8101a779>] ? read_tsc+0x9/0x20
Mar 20 09:09:43 raynor kernel: [  360.857161]  [<ffffffff81094fad>] ? ktime_get_ts+0xad/0xe0
Mar 20 09:09:43 raynor kernel: [  360.857162]  [<ffffffff810c78f4>] do_acct_process+0x2f4/0x350
Mar 20 09:09:43 raynor kernel: [  360.857165]  [<ffffffff810d6801>] ? queue_stop_cpus_work+0x51/0xd0
Mar 20 09:09:43 raynor kernel: [  360.857167]  [<ffffffff810c79b6>] acct_process_in_ns+0x66/0x90
Mar 20 09:09:43 raynor kernel: [  360.857169]  [<ffffffff810c80c0>] acct_process+0x30/0x50
Mar 20 09:09:43 raynor kernel: [  360.857172]  [<ffffffff8106bc76>] do_exit+0x2c6/0x420
Mar 20 09:09:43 raynor kernel: [  360.857174]  [<ffffffff810d69f0>] ? __stop_cpus+0x80/0x80
Mar 20 09:09:43 raynor kernel: [  360.857176]  [<ffffffff8108a396>] kthread+0x86/0xa0
Mar 20 09:09:43 raynor kernel: [  360.857178]  [<ffffffff81682734>] kernel_thread_helper+0x4/0x10
Mar 20 09:09:43 raynor kernel: [  360.857180]  [<ffffffff8108a310>] ? flush_kthread_worker+0xa0/0xa0
Mar 20 09:09:43 raynor kernel: [  360.857182]  [<ffffffff81682730>] ? gs_change+0x13/0x13
Mar 20 09:09:43 raynor kernel: [  360.857184] INFO: task kworker/4:0:22 blocked for more than 120 seconds.
Mar 20 09:09:43 raynor kernel: [  360.857712] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 20 09:09:43 raynor kernel: [  360.858251] kworker/4:0     D ffffffff81806240     0    22      2 0x00000000
Mar 20 09:09:43 raynor kernel: [  360.858253]  ffff88042580dab0 0000000000000046 ffff880425805b80 ffffffffffffffff
Mar 20 09:09:43 raynor kernel: [  360.858255]  ffff88042580dfd8 ffff88042580dfd8 ffff88042580dfd8 0000000000013840
Mar 20 09:09:43 raynor kernel: [  360.858256]  ffff8804258196e0 ffff880425805b80 ffff88042580db68 ffff88041d42aa90
Mar 20 09:09:43 raynor kernel: [  360.858258] Call Trace:
Mar 20 09:09:43 raynor kernel: [  360.858260]  [<ffffffff8167609f>] schedule+0x3f/0x60
Mar 20 09:09:43 raynor kernel: [  360.858261]  [<ffffffff81676ea7>] __mutex_lock_slowpath+0xd7/0x150
Mar 20 09:09:43 raynor kernel: [  360.858263]  [<ffffffff81676aba>] mutex_lock+0x2a/0x50
Mar 20 09:09:43 raynor kernel: [  360.858264]  [<ffffffff8112e3b6>] generic_file_aio_write+0x56/0xe0
Mar 20 09:09:43 raynor kernel: [  360.858266]  [<ffffffff813088fa>] ? freed_request+0x4a/0x70
Mar 20 09:09:43 raynor kernel: [  360.858267]  [<ffffffff81225edf>] ext4_file_write+0xbf/0x260
Mar 20 09:09:43 raynor kernel: [  360.858268]  [<ffffffff81308c99>] ? blk_put_request+0x49/0x60
Mar 20 09:09:43 raynor kernel: [  360.858270]  [<ffffffff814434ef>] ? scsi_execute+0x11f/0x180
Mar 20 09:09:43 raynor kernel: [  360.858271]  [<ffffffff811772ab>] ? kfree+0x3b/0x140
Mar 20 09:09:43 raynor kernel: [  360.858273]  [<ffffffff8118c572>] do_sync_write+0xd2/0x110
Mar 20 09:09:43 raynor kernel: [  360.858274]  [<ffffffff81052012>] ? ttwu_queue+0x92/0xd0
Mar 20 09:09:43 raynor kernel: [  360.858276]  [<ffffffff8105fa4e>] ? try_to_wake_up+0x18e/0x200
Mar 20 09:09:43 raynor kernel: [  360.858277]  [<ffffffff8101a779>] ? read_tsc+0x9/0x20
Mar 20 09:09:43 raynor kernel: [  360.858278]  [<ffffffff81094fad>] ? ktime_get_ts+0xad/0xe0
Mar 20 09:09:43 raynor kernel: [  360.858279]  [<ffffffff810c78f4>] do_acct_process+0x2f4/0x350
Mar 20 09:09:43 raynor kernel: [  360.858281]  [<ffffffff810c79b6>] acct_process_in_ns+0x66/0x90
Mar 20 09:09:43 raynor kernel: [  360.858282]  [<ffffffff810c80c0>] acct_process+0x30/0x50
Mar 20 09:09:43 raynor kernel: [  360.858283]  [<ffffffff8106bc76>] do_exit+0x2c6/0x420
Mar 20 09:09:43 raynor kernel: [  360.858285]  [<ffffffff810859e0>] ? manage_workers.isra.29+0x130/0x130
Mar 20 09:09:43 raynor kernel: [  360.858286]  [<ffffffff8108a396>] kthread+0x86/0xa0
Mar 20 09:09:43 raynor kernel: [  360.858287]  [<ffffffff81682734>] kernel_thread_helper+0x4/0x10
Mar 20 09:09:43 raynor kernel: [  360.858289]  [<ffffffff8108a310>] ? flush_kthread_worker+0xa0/0xa0
Mar 20 09:09:43 raynor kernel: [  360.858290]  [<ffffffff81682730>] ? gs_change+0x13/0x13
Mar 20 09:14:07 raynor kernel: [  624.564436] INFO: task kworker/1:0:9 blocked for more than 60 seconds.
Mar 20 09:14:07 raynor kernel: [  624.564926] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Mar 20 09:14:07 raynor kernel: [  624.565423] kworker/1:0     D ffffffff81806240     0     9      2 0x00000000
Mar 20 09:14:07 raynor kernel: [  624.565425]  ffff880425f3dab0 0000000000000046 ffff880425f344e8 0000000000000001
Mar 20 09:14:07 raynor kernel: [  624.565427]  ffff880425f3dfd8 ffff880425f3dfd8 ffff880425f3dfd8 0000000000013840
Mar 20 09:14:07 raynor kernel: [  624.565429]  ffff880425fc96e0 ffff880425f344a0 ffff880425f3da90 ffff88041d42aa90
Mar 20 09:14:07 raynor kernel: [  624.565431] Call Trace:
Mar 20 09:14:07 raynor kernel: [  624.565436]  [<ffffffff8167609f>] schedule+0x3f/0x60
Mar 20 09:14:07 raynor kernel: [  624.565438]  [<ffffffff81676ea7>] __mutex_lock_slowpath+0xd7/0x150
Mar 20 09:14:07 raynor kernel: [  624.565440]  [<ffffffff81676aba>] mutex_lock+0x2a/0x50
Mar 20 09:14:07 raynor kernel: [  624.565442]  [<ffffffff8112e3b6>] generic_file_aio_write+0x56/0xe0
Mar 20 09:14:07 raynor kernel: [  624.565444]  [<ffffffff8167609f>] ? schedule+0x3f/0x60
Mar 20 09:14:07 raynor kernel: [  624.565446]  [<ffffffff81225edf>] ext4_file_write+0xbf/0x260
Mar 20 09:14:07 raynor kernel: [  624.565448]  [<ffffffff8103dbb9>] ? default_spin_lock_flags+0x9/0x10
Mar 20 09:14:07 raynor kernel: [  624.565449]  [<ffffffff8167823e>] ? _raw_spin_lock_irqsave+0x2e/0x40
Mar 20 09:14:07 raynor kernel: [  624.565452]  [<ffffffff8118c572>] do_sync_write+0xd2/0x110
Mar 20 09:14:07 raynor kernel: [  624.565454]  [<ffffffff81052012>] ? ttwu_queue+0x92/0xd0
Mar 20 09:14:07 raynor kernel: [  624.565456]  [<ffffffff8105fa4e>] ? try_to_wake_up+0x18e/0x200
Mar 20 09:14:07 raynor kernel: [  624.565457]  [<ffffffff8101a779>] ? read_tsc+0x9/0x20
Mar 20 09:14:07 raynor kernel: [  624.565459]  [<ffffffff81094fad>] ? ktime_get_ts+0xad/0xe0
Mar 20 09:14:07 raynor kernel: [  624.565461]  [<ffffffff810c78f4>] do_acct_process+0x2f4/0x350
Mar 20 09:14:07 raynor kernel: [  624.565463]  [<ffffffff810c79b6>] acct_process_in_ns+0x66/0x90
Mar 20 09:14:07 raynor kernel: [  624.565464]  [<ffffffff810c80c0>] acct_process+0x30/0x50
Mar 20 09:14:07 raynor kernel: [  624.565466]  [<ffffffff8106bc76>] do_exit+0x2c6/0x420
Mar 20 09:14:07 raynor kernel: [  624.565468]  [<ffffffff810859e0>] ? manage_workers.isra.29+0x130/0x130
Mar 20 09:14:07 raynor kernel: [  624.565470]  [<ffffffff8108a396>] kthread+0x86/0xa0
Mar 20 09:14:07 raynor kernel: [  624.565472]  [<ffffffff81682734>] kernel_thread_helper+0x4/0x10
Mar 20 09:14:07 raynor kernel: [  624.565473]  [<ffffffff8108a310>] ? flush_kthread_worker+0xa0/0xa0
Mar 20 09:14:07 raynor kernel: [  624.565474]  [<ffffffff81682730>] ? gs_change+0x13/0x13

---


Seems like a bug, isn't it ?  Is this caused by tuxonice or is this a bug from vanilla kernel? Thanks.


BR,

Nai Xia