[Bug 561210] Re: Writing big files to NFS target causes system lock up

Tue Jun 22 21:23:17 UTC 2010

@Jim: That looks to me like a test case :)

All this information leads me to the same conclusion that those blocking behavior occurs most commonly when the system runs out of free RAM and starts to swap heavily.

I'm currently running a vanilla kernel 2.6.35-rc3 and with that I wasn't
able to reproduce some blocking here, but what I noticed was that when
the system starts this heavy swapping even my hardware accelerated mouse
cursor get stuck sometimes (reminds me on an old crappy windows box I
used to have). And this plus the fact that the whole user interface (at
least with KDE4) locks up sometimes points me to something that isn't
necessarily related to NFS itself.

As every file operation in Linux also uses the system memory to speed up
things it could be that the priority of what gets swapped out and what
swapped in doesn't suite the individual needs. In the worst case if
something like plasma-desktop is chosen to be swapped out then parts of
it immediately are scheduled for swap-in as plasma-desktop updates
periodically. That way the wrong swapping strategy could introduce this
issue.

On the other hand I don't understand why the hell is some heavy swapping
able to interfere a hardware accelerated mouse cursor? This lonely
symptom leads me to another pointer: interrupt handling. But then I
don't know enough about that thing to go any further.

I just issued a test on my 2.6.35-rc3 box:
- set up an NFS mount with rsize=128,wsize=128
- make the system memory (4GB) almost completely used by other processes (very few file cache/buffered)
- issue a "gunzip" of a 4.1 GiB file from the NFS mount to the NFS mount

And now guess what?

Yes, I got those hung tasks again even with a much newer kernel, so the
problem isn't addressed upstream and can't be in lucid.

Although this time it is a bit different because I don't get NFS related
backtraces here. Instead (and what I currently think is more of a reason
to this problem) I always get some calls for memory allocation and/or
paging requests. So the system is heavily swapping and the swapping
needs time as we all know.

But instead just waiting for the scheduled operation to complete it
"blocks" and therefore interferes user interaction at all.

To verify that problem I just made up some KVM's on my machine at work
(a 6-core AMD64, 8GiB RAM) and even without having any NFS mounts or
exports I got some very similar behavior. Although I didn't provoke a
complete lockup yet (well, I need to do some work there), I also got
temporarily freezing "hardware accelerated" mouse cursor and completely
non-responsive desktop (at least for some seconds up to a minute).

Here it goes for my machine with kernel 2.6.35-rc3:

[240602.803784] INFO: task kwin:2102 blocked for more than 120 seconds.
[240602.803787] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[240602.803789] kwin          D 00000000ffffffff     0  2102   2100 0x00000000
[240602.803793]  ffff8801281d93d8 0000000000000086 ffff880073c09cc8 0000000000015840
[240602.803796]  ffff8801281d9fd8 0000000000015840 ffff8801281d9fd8 ffff88012a2196d0
[240602.803798]  0000000000015840 0000000000015840 ffff8801281d9fd8 0000000000015840
[240602.803800] Call Trace:
[240602.803806]  [<ffffffff81032ca9>] ? default_spin_lock_flags+0x9/0x10
[240602.803809]  [<ffffffff810eda70>] ? sync_page+0x0/0x50
[240602.803812]  [<ffffffff81534327>] io_schedule+0x47/0x70
[240602.803814]  [<ffffffff810edaad>] sync_page+0x3d/0x50
[240602.803816]  [<ffffffff81534bdf>] __wait_on_bit+0x5f/0x90
[240602.803818]  [<ffffffff810edc63>] wait_on_page_bit+0x73/0x80
[240602.803821]  [<ffffffff8107a720>] ? wake_bit_function+0x0/0x40
[240602.803824]  [<ffffffff810fb266>] shrink_page_list+0x176/0x580
[240602.803826]  [<ffffffff8106b430>] ? process_timeout+0x0/0x10
[240602.803828]  [<ffffffff81032ca9>] ? default_spin_lock_flags+0x9/0x10
[240602.803830]  [<ffffffff8107a877>] ? finish_wait+0x67/0x90
[240602.803832]  [<ffffffff8110552e>] ? congestion_wait+0x7e/0x90
[240602.803834]  [<ffffffff8107a6e0>] ? autoremove_wake_function+0x0/0x40
[240602.803837]  [<ffffffff810fbd54>] shrink_inactive_list+0x6e4/0x7f0
[240602.803839]  [<ffffffff81047e18>] ? update_curr+0xf8/0x1e0
[240602.803842]  [<ffffffff810f5f7a>] ? determine_dirtyable_memory+0x1a/0x30
[240602.803844]  [<ffffffff810f6027>] ? get_dirty_limits+0x27/0x2f0
[240602.803846]  [<ffffffff8105197c>] ? try_to_wake_up+0xcc/0x400
[240602.803848]  [<ffffffff810fc1cb>] shrink_zone+0x36b/0x4b0
[240602.803850]  [<ffffffff810fc403>] do_try_to_free_pages+0xf3/0x440
[240602.803852]  [<ffffffff810fc8f8>] try_to_free_pages+0x68/0x70
[240602.803854]  [<ffffffff810f4428>] __alloc_pages_nodemask+0x3e8/0x6f0
[240602.803857]  [<ffffffff81444bef>] ? __alloc_skb+0x4f/0x170
[240602.803859]  [<ffffffff8112ae52>] kmalloc_large_node+0x62/0xb0
[240602.803861]  [<ffffffff8112e6fc>] __kmalloc_node_track_caller+0x13c/0x1f0
[240602.803864]  [<ffffffff81440a64>] ? sock_alloc_send_pskb+0x1d4/0x340
[240602.803866]  [<ffffffff81444c23>] __alloc_skb+0x83/0x170
[240602.803868]  [<ffffffff81440a64>] sock_alloc_send_pskb+0x1d4/0x340
[240602.803870]  [<ffffffff81440be5>] sock_alloc_send_skb+0x15/0x20
[240602.803873]  [<ffffffff814d8cb5>] unix_stream_sendmsg+0x275/0x3e0
[240602.803875]  [<ffffffff8153664e>] ? _raw_spin_lock+0xe/0x20
[240602.803877]  [<ffffffff8143bfde>] sock_aio_write+0x14e/0x160
[240602.803879]  [<ffffffff8143be90>] ? sock_aio_write+0x0/0x160
[240602.803882]  [<ffffffff8113cad3>] do_sync_readv_writev+0xd3/0x110
[240602.803884]  [<ffffffff811476a3>] ? putname+0x33/0x50
[240602.803886]  [<ffffffff8114b2f2>] ? user_path_at+0x62/0xa0
[240602.803889]  [<ffffffff81248256>] ? security_file_permission+0x16/0x20
[240602.803891]  [<ffffffff8113db5f>] do_readv_writev+0xcf/0x1f0
[240602.803894]  [<ffffffff8113dcc8>] vfs_writev+0x48/0x60
[240602.803895]  [<ffffffff8113ddf1>] sys_writev+0x51/0xb0
[240602.803897]  [<ffffffff8114f29c>] ? sys_poll+0x7c/0x110
[240602.803900]  [<ffffffff8100a072>] system_call_fastpath+0x16/0x1b
[241082.803794] INFO: task konsole:2145 blocked for more than 120 seconds.
[241082.803798] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[241082.803800] konsole       D 00000001016f201d     0  2145      1 0x00000000
[241082.803803]  ffff88000d8cf3d8 0000000000000082 ffff880000000000 0000000000015840
[241082.803806]  ffff88000d8cffd8 0000000000015840 ffff88000d8cffd8 ffff88000d8c16d0
[241082.803808]  0000000000015840 0000000000015840 ffff88000d8cffd8 0000000000015840
[241082.803810] Call Trace:
[241082.803817]  [<ffffffff810eda70>] ? sync_page+0x0/0x50
[241082.803820]  [<ffffffff81534327>] io_schedule+0x47/0x70
[241082.803822]  [<ffffffff810edaad>] sync_page+0x3d/0x50
[241082.803824]  [<ffffffff81534bdf>] __wait_on_bit+0x5f/0x90
[241082.803827]  [<ffffffff810edc63>] wait_on_page_bit+0x73/0x80
[241082.803830]  [<ffffffff8107a720>] ? wake_bit_function+0x0/0x40
[241082.803833]  [<ffffffff810fb266>] shrink_page_list+0x176/0x580
[241082.803835]  [<ffffffff8106b430>] ? process_timeout+0x0/0x10
[241082.803837]  [<ffffffff81032ca9>] ? default_spin_lock_flags+0x9/0x10
[241082.803840]  [<ffffffff8107a877>] ? finish_wait+0x67/0x90
[241082.803842]  [<ffffffff8110552e>] ? congestion_wait+0x7e/0x90
[241082.803844]  [<ffffffff8107a6e0>] ? autoremove_wake_function+0x0/0x40
[241082.803846]  [<ffffffff810fbd54>] shrink_inactive_list+0x6e4/0x7f0
[241082.803849]  [<ffffffff81047e18>] ? update_curr+0xf8/0x1e0
[241082.803851]  [<ffffffff810532d5>] ? check_preempt_wakeup+0x1c5/0x290
[241082.803854]  [<ffffffff810f5f7a>] ? determine_dirtyable_memory+0x1a/0x30
[241082.803856]  [<ffffffff810f6027>] ? get_dirty_limits+0x27/0x2f0
[241082.803857]  [<ffffffff8105197c>] ? try_to_wake_up+0xcc/0x400
[241082.803860]  [<ffffffff810fc1cb>] shrink_zone+0x36b/0x4b0
[241082.803862]  [<ffffffff810fc403>] do_try_to_free_pages+0xf3/0x440
[241082.803864]  [<ffffffff810fc8f8>] try_to_free_pages+0x68/0x70
[241082.803866]  [<ffffffff810f4428>] __alloc_pages_nodemask+0x3e8/0x6f0
[241082.803869]  [<ffffffff8112ae52>] kmalloc_large_node+0x62/0xb0
[241082.803871]  [<ffffffff8112e6fc>] __kmalloc_node_track_caller+0x13c/0x1f0
[241082.803874]  [<ffffffff81440a64>] ? sock_alloc_send_pskb+0x1d4/0x340
[241082.803876]  [<ffffffff81444bef>] ? __alloc_skb+0x4f/0x170
[241082.803878]  [<ffffffff81444c23>] __alloc_skb+0x83/0x170
[241082.803880]  [<ffffffff81440a64>] sock_alloc_send_pskb+0x1d4/0x340
[241082.803882]  [<ffffffff81440be5>] sock_alloc_send_skb+0x15/0x20
[241082.803885]  [<ffffffff814d8cb5>] unix_stream_sendmsg+0x275/0x3e0
[241082.803887]  [<ffffffff8143bfde>] sock_aio_write+0x14e/0x160
[241082.803890]  [<ffffffff8114e940>] ? pollwake+0x0/0x60
[241082.803892]  [<ffffffff8143be90>] ? sock_aio_write+0x0/0x160
[241082.803894]  [<ffffffff8113cad3>] do_sync_readv_writev+0xd3/0x110
[241082.803896]  [<ffffffff8113cd0a>] ? do_sync_read+0xda/0x120
[241082.803899]  [<ffffffff81248256>] ? security_file_permission+0x16/0x20
[241082.803901]  [<ffffffff8113db5f>] do_readv_writev+0xcf/0x1f0
[241082.803903]  [<ffffffff81248256>] ? security_file_permission+0x16/0x20
[241082.803905]  [<ffffffff8113dcc8>] vfs_writev+0x48/0x60
[241082.803907]  [<ffffffff8113ddf1>] sys_writev+0x51/0xb0
[241082.803909]  [<ffffffff8114f29c>] ? sys_poll+0x7c/0x110
[241082.803912]  [<ffffffff8100a072>] system_call_fastpath+0x16/0x1b
[241202.803836] INFO: task konsole:2145 blocked for more than 120 seconds.
[241202.803845] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[241202.803851] konsole       D 00000001016f201d     0  2145      1 0x00000000
[241202.803867]  ffff88000d8cf3d8 0000000000000082 ffff880000000000 0000000000015840
[241202.803877]  ffff88000d8cffd8 0000000000015840 ffff88000d8cffd8 ffff88000d8c16d0
[241202.803887]  0000000000015840 0000000000015840 ffff88000d8cffd8 0000000000015840
[241202.803895] Call Trace:
[241202.803911]  [<ffffffff810eda70>] ? sync_page+0x0/0x50
[241202.803922]  [<ffffffff81534327>] io_schedule+0x47/0x70
[241202.803931]  [<ffffffff810edaad>] sync_page+0x3d/0x50
[241202.803938]  [<ffffffff81534bdf>] __wait_on_bit+0x5f/0x90
[241202.803947]  [<ffffffff810edc63>] wait_on_page_bit+0x73/0x80
[241202.803956]  [<ffffffff8107a720>] ? wake_bit_function+0x0/0x40
[241202.803966]  [<ffffffff810fb266>] shrink_page_list+0x176/0x580
[241202.803973]  [<ffffffff8106b430>] ? process_timeout+0x0/0x10
[241202.803981]  [<ffffffff81032ca9>] ? default_spin_lock_flags+0x9/0x10
[241202.803988]  [<ffffffff8107a877>] ? finish_wait+0x67/0x90
[241202.803996]  [<ffffffff8110552e>] ? congestion_wait+0x7e/0x90
[241202.804004]  [<ffffffff8107a6e0>] ? autoremove_wake_function+0x0/0x40
[241202.804013]  [<ffffffff810fbd54>] shrink_inactive_list+0x6e4/0x7f0
[241202.804023]  [<ffffffff81047e18>] ? update_curr+0xf8/0x1e0
[241202.804031]  [<ffffffff810532d5>] ? check_preempt_wakeup+0x1c5/0x290
[241202.804039]  [<ffffffff810f5f7a>] ? determine_dirtyable_memory+0x1a/0x30
[241202.804047]  [<ffffffff810f6027>] ? get_dirty_limits+0x27/0x2f0
[241202.804054]  [<ffffffff8105197c>] ? try_to_wake_up+0xcc/0x400
[241202.804063]  [<ffffffff810fc1cb>] shrink_zone+0x36b/0x4b0
[241202.804072]  [<ffffffff810fc403>] do_try_to_free_pages+0xf3/0x440
[241202.804080]  [<ffffffff810fc8f8>] try_to_free_pages+0x68/0x70
[241202.804088]  [<ffffffff810f4428>] __alloc_pages_nodemask+0x3e8/0x6f0
[241202.804098]  [<ffffffff8112ae52>] kmalloc_large_node+0x62/0xb0
[241202.804106]  [<ffffffff8112e6fc>] __kmalloc_node_track_caller+0x13c/0x1f0
[241202.804115]  [<ffffffff81440a64>] ? sock_alloc_send_pskb+0x1d4/0x340
[241202.804123]  [<ffffffff81444bef>] ? __alloc_skb+0x4f/0x170
[241202.804129]  [<ffffffff81444c23>] __alloc_skb+0x83/0x170
[241202.804137]  [<ffffffff81440a64>] sock_alloc_send_pskb+0x1d4/0x340
[241202.804146]  [<ffffffff81440be5>] sock_alloc_send_skb+0x15/0x20
[241202.804155]  [<ffffffff814d8cb5>] unix_stream_sendmsg+0x275/0x3e0
[241202.804163]  [<ffffffff8143bfde>] sock_aio_write+0x14e/0x160
[241202.804172]  [<ffffffff8114e940>] ? pollwake+0x0/0x60
[241202.804179]  [<ffffffff8143be90>] ? sock_aio_write+0x0/0x160
[241202.804187]  [<ffffffff8113cad3>] do_sync_readv_writev+0xd3/0x110
[241202.804195]  [<ffffffff8113cd0a>] ? do_sync_read+0xda/0x120
[241202.804205]  [<ffffffff81248256>] ? security_file_permission+0x16/0x20
[241202.804213]  [<ffffffff8113db5f>] do_readv_writev+0xcf/0x1f0
[241202.804222]  [<ffffffff81248256>] ? security_file_permission+0x16/0x20
[241202.804230]  [<ffffffff8113dcc8>] vfs_writev+0x48/0x60
[241202.804237]  [<ffffffff8113ddf1>] sys_writev+0x51/0xb0
[241202.804244]  [<ffffffff8114f29c>] ? sys_poll+0x7c/0x110
[241202.804253]  [<ffffffff8100a072>] system_call_fastpath+0x16/0x1b
[241202.804304] INFO: task firefox-bin:12398 blocked for more than 120 seconds.
[241202.804309] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[241202.804314] firefox-bin   D 00000000ffffffff     0 12398  12394 0x00000000
[241202.804324]  ffff880078a592f8 0000000000000086 0000000000000400 0000000000015840
[241202.804333]  ffff880078a59fd8 0000000000015840 ffff880078a59fd8 ffff88004b395b40
[241202.804341]  0000000000015840 0000000000015840 ffff880078a59fd8 0000000000015840
[241202.804350] Call Trace:
[241202.804357]  [<ffffffff81032ca9>] ? default_spin_lock_flags+0x9/0x10
[241202.804365]  [<ffffffff810eda70>] ? sync_page+0x0/0x50
[241202.804373]  [<ffffffff81534327>] io_schedule+0x47/0x70
[241202.804381]  [<ffffffff810edaad>] sync_page+0x3d/0x50
[241202.804388]  [<ffffffff81534bdf>] __wait_on_bit+0x5f/0x90
[241202.804397]  [<ffffffff810edc63>] wait_on_page_bit+0x73/0x80
[241202.804404]  [<ffffffff8107a720>] ? wake_bit_function+0x0/0x40
[241202.804412]  [<ffffffff8153485d>] ? schedule_timeout+0x19d/0x310
[241202.804420]  [<ffffffff810fb266>] shrink_page_list+0x176/0x580
[241202.804427]  [<ffffffff8106b430>] ? process_timeout+0x0/0x10
[241202.804435]  [<ffffffff8110552e>] ? congestion_wait+0x7e/0x90
[241202.804442]  [<ffffffff8107a6e0>] ? autoremove_wake_function+0x0/0x40
[241202.804451]  [<ffffffff810fbd54>] shrink_inactive_list+0x6e4/0x7f0
[241202.804460]  [<ffffffff81047e18>] ? update_curr+0xf8/0x1e0
[241202.804469]  [<ffffffff8153664e>] ? _raw_spin_lock+0xe/0x20
[241202.804477]  [<ffffffff810483dd>] ? task_rq_lock+0x5d/0xa0
[241202.804484]  [<ffffffff8105197c>] ? try_to_wake_up+0xcc/0x400
[241202.804492]  [<ffffffff810fc1cb>] shrink_zone+0x36b/0x4b0
[241202.804501]  [<ffffffff810fc403>] do_try_to_free_pages+0xf3/0x440
[241202.804510]  [<ffffffff810fc8f8>] try_to_free_pages+0x68/0x70
[241202.804518]  [<ffffffff810f4428>] __alloc_pages_nodemask+0x3e8/0x6f0
[241202.804526]  [<ffffffff811255ca>] alloc_pages_current+0x9a/0x100
[241202.804533]  [<ffffffff8112b725>] new_slab+0x225/0x2c0
[241202.804541]  [<ffffffff8112d333>] __slab_alloc+0x163/0x500
[241202.804549]  [<ffffffff81440a64>] ? sock_alloc_send_pskb+0x1d4/0x340
[241202.804558]  [<ffffffff8112e671>] __kmalloc_node_track_caller+0xb1/0x1f0
[241202.804566]  [<ffffffff81440a64>] ? sock_alloc_send_pskb+0x1d4/0x340
[241202.804573]  [<ffffffff81444bef>] ? __alloc_skb+0x4f/0x170
[241202.804579]  [<ffffffff81444c23>] __alloc_skb+0x83/0x170
[241202.804587]  [<ffffffff81440a64>] sock_alloc_send_pskb+0x1d4/0x340
[241202.804595]  [<ffffffff81440be5>] sock_alloc_send_skb+0x15/0x20
[241202.804604]  [<ffffffff814d8cb5>] unix_stream_sendmsg+0x275/0x3e0
[241202.804612]  [<ffffffff810eda70>] ? sync_page+0x0/0x50
[241202.804620]  [<ffffffff8143bfde>] sock_aio_write+0x14e/0x160
[241202.804627]  [<ffffffff8143be90>] ? sock_aio_write+0x0/0x160
[241202.804635]  [<ffffffff8113cad3>] do_sync_readv_writev+0xd3/0x110
[241202.804643]  [<ffffffff810eda70>] ? sync_page+0x0/0x50
[241202.804651]  [<ffffffff81108d99>] ? __do_fault+0x459/0x540
[241202.804660]  [<ffffffff81248256>] ? security_file_permission+0x16/0x20
[241202.804668]  [<ffffffff8113db5f>] do_readv_writev+0xcf/0x1f0
[241202.804676]  [<ffffffff8113dcc8>] vfs_writev+0x48/0x60
[241202.804683]  [<ffffffff8113ddf1>] sys_writev+0x51/0xb0
[241202.804691]  [<ffffffff8114f29c>] ? sys_poll+0x7c/0x110
[241202.804699]  [<ffffffff8100a072>] system_call_fastpath+0x16/0x1b
[241322.803828] INFO: task konsole:2145 blocked for more than 120 seconds.
[241322.803837] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[241322.803844] konsole       D 00000001016f201d     0  2145      1 0x00000000
[241322.803856]  ffff88000d8cf3d8 0000000000000082 ffff880000000000 0000000000015840
[241322.803866]  ffff88000d8cffd8 0000000000015840 ffff88000d8cffd8 ffff88000d8c16d0
[241322.803875]  0000000000015840 0000000000015840 ffff88000d8cffd8 0000000000015840
[241322.803884] Call Trace:
[241322.803899]  [<ffffffff810eda70>] ? sync_page+0x0/0x50
[241322.803910]  [<ffffffff81534327>] io_schedule+0x47/0x70
[241322.803919]  [<ffffffff810edaad>] sync_page+0x3d/0x50
[241322.803927]  [<ffffffff81534bdf>] __wait_on_bit+0x5f/0x90
[241322.803935]  [<ffffffff810edc63>] wait_on_page_bit+0x73/0x80
[241322.803944]  [<ffffffff8107a720>] ? wake_bit_function+0x0/0x40
[241322.803954]  [<ffffffff810fb266>] shrink_page_list+0x176/0x580
[241322.803961]  [<ffffffff8106b430>] ? process_timeout+0x0/0x10
[241322.803969]  [<ffffffff81032ca9>] ? default_spin_lock_flags+0x9/0x10
[241322.803977]  [<ffffffff8107a877>] ? finish_wait+0x67/0x90
[241322.803985]  [<ffffffff8110552e>] ? congestion_wait+0x7e/0x90
[241322.803993]  [<ffffffff8107a6e0>] ? autoremove_wake_function+0x0/0x40
[241322.804001]  [<ffffffff810fbd54>] shrink_inactive_list+0x6e4/0x7f0
[241322.804011]  [<ffffffff81047e18>] ? update_curr+0xf8/0x1e0
[241322.804020]  [<ffffffff810532d5>] ? check_preempt_wakeup+0x1c5/0x290
[241322.804028]  [<ffffffff810f5f7a>] ? determine_dirtyable_memory+0x1a/0x30
[241322.804035]  [<ffffffff810f6027>] ? get_dirty_limits+0x27/0x2f0
[241322.804043]  [<ffffffff8105197c>] ? try_to_wake_up+0xcc/0x400
[241322.804051]  [<ffffffff810fc1cb>] shrink_zone+0x36b/0x4b0
[241322.804060]  [<ffffffff810fc403>] do_try_to_free_pages+0xf3/0x440
[241322.804069]  [<ffffffff810fc8f8>] try_to_free_pages+0x68/0x70
[241322.804077]  [<ffffffff810f4428>] __alloc_pages_nodemask+0x3e8/0x6f0
[241322.804086]  [<ffffffff8112ae52>] kmalloc_large_node+0x62/0xb0
[241322.804094]  [<ffffffff8112e6fc>] __kmalloc_node_track_caller+0x13c/0x1f0
[241322.804104]  [<ffffffff81440a64>] ? sock_alloc_send_pskb+0x1d4/0x340
[241322.804111]  [<ffffffff81444bef>] ? __alloc_skb+0x4f/0x170
[241322.804117]  [<ffffffff81444c23>] __alloc_skb+0x83/0x170
[241322.804125]  [<ffffffff81440a64>] sock_alloc_send_pskb+0x1d4/0x340
[241322.804134]  [<ffffffff81440be5>] sock_alloc_send_skb+0x15/0x20
[241322.804144]  [<ffffffff814d8cb5>] unix_stream_sendmsg+0x275/0x3e0
[241322.804152]  [<ffffffff8143bfde>] sock_aio_write+0x14e/0x160
[241322.804161]  [<ffffffff8114e940>] ? pollwake+0x0/0x60
[241322.804168]  [<ffffffff8143be90>] ? sock_aio_write+0x0/0x160
[241322.804176]  [<ffffffff8113cad3>] do_sync_readv_writev+0xd3/0x110
[241322.804184]  [<ffffffff8113cd0a>] ? do_sync_read+0xda/0x120
[241322.804194]  [<ffffffff81248256>] ? security_file_permission+0x16/0x20
[241322.804202]  [<ffffffff8113db5f>] do_readv_writev+0xcf/0x1f0
[241322.804210]  [<ffffffff81248256>] ? security_file_permission+0x16/0x20
[241322.804218]  [<ffffffff8113dcc8>] vfs_writev+0x48/0x60
[241322.804226]  [<ffffffff8113ddf1>] sys_writev+0x51/0xb0
[241322.804233]  [<ffffffff8114f29c>] ? sys_poll+0x7c/0x110
[241322.804242]  [<ffffffff8100a072>] system_call_fastpath+0x16/0x1b
[241322.804295] INFO: task firefox-bin:12398 blocked for more than 120 seconds.
[241322.804299] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[241322.804305] firefox-bin   D 00000000ffffffff     0 12398  12394 0x00000000
[241322.804314]  ffff880078a592f8 0000000000000086 0000000000000400 0000000000015840
[241322.804323]  ffff880078a59fd8 0000000000015840 ffff880078a59fd8 ffff88004b395b40
[241322.804332]  0000000000015840 0000000000015840 ffff880078a59fd8 0000000000015840
[241322.804340] Call Trace:
[241322.804347]  [<ffffffff81032ca9>] ? default_spin_lock_flags+0x9/0x10
[241322.804356]  [<ffffffff810eda70>] ? sync_page+0x0/0x50
[241322.804363]  [<ffffffff81534327>] io_schedule+0x47/0x70
[241322.804371]  [<ffffffff810edaad>] sync_page+0x3d/0x50
[241322.804378]  [<ffffffff81534bdf>] __wait_on_bit+0x5f/0x90
[241322.804387]  [<ffffffff810edc63>] wait_on_page_bit+0x73/0x80
[241322.804394]  [<ffffffff8107a720>] ? wake_bit_function+0x0/0x40
[241322.804402]  [<ffffffff8153485d>] ? schedule_timeout+0x19d/0x310
[241322.804411]  [<ffffffff810fb266>] shrink_page_list+0x176/0x580
[241322.804417]  [<ffffffff8106b430>] ? process_timeout+0x0/0x10
[241322.804426]  [<ffffffff8110552e>] ? congestion_wait+0x7e/0x90
[241322.804433]  [<ffffffff8107a6e0>] ? autoremove_wake_function+0x0/0x40
[241322.804442]  [<ffffffff810fbd54>] shrink_inactive_list+0x6e4/0x7f0
[241322.804450]  [<ffffffff81047e18>] ? update_curr+0xf8/0x1e0
[241322.804459]  [<ffffffff8153664e>] ? _raw_spin_lock+0xe/0x20
[241322.804467]  [<ffffffff810483dd>] ? task_rq_lock+0x5d/0xa0
[241322.804474]  [<ffffffff8105197c>] ? try_to_wake_up+0xcc/0x400
[241322.804483]  [<ffffffff810fc1cb>] shrink_zone+0x36b/0x4b0
[241322.804492]  [<ffffffff810fc403>] do_try_to_free_pages+0xf3/0x440
[241322.804500]  [<ffffffff810fc8f8>] try_to_free_pages+0x68/0x70
[241322.804508]  [<ffffffff810f4428>] __alloc_pages_nodemask+0x3e8/0x6f0
[241322.804517]  [<ffffffff811255ca>] alloc_pages_current+0x9a/0x100
[241322.804524]  [<ffffffff8112b725>] new_slab+0x225/0x2c0
[241322.804532]  [<ffffffff8112d333>] __slab_alloc+0x163/0x500
[241322.804540]  [<ffffffff81440a64>] ? sock_alloc_send_pskb+0x1d4/0x340
[241322.804548]  [<ffffffff8112e671>] __kmalloc_node_track_caller+0xb1/0x1f0
[241322.804557]  [<ffffffff81440a64>] ? sock_alloc_send_pskb+0x1d4/0x340
[241322.804563]  [<ffffffff81444bef>] ? __alloc_skb+0x4f/0x170
[241322.804569]  [<ffffffff81444c23>] __alloc_skb+0x83/0x170
[241322.804577]  [<ffffffff81440a64>] sock_alloc_send_pskb+0x1d4/0x340
[241322.804586]  [<ffffffff81440be5>] sock_alloc_send_skb+0x15/0x20
[241322.804595]  [<ffffffff814d8cb5>] unix_stream_sendmsg+0x275/0x3e0
[241322.804603]  [<ffffffff810eda70>] ? sync_page+0x0/0x50
[241322.804610]  [<ffffffff8143bfde>] sock_aio_write+0x14e/0x160
[241322.804618]  [<ffffffff8143be90>] ? sock_aio_write+0x0/0x160
[241322.804626]  [<ffffffff8113cad3>] do_sync_readv_writev+0xd3/0x110
[241322.804634]  [<ffffffff810eda70>] ? sync_page+0x0/0x50
[241322.804642]  [<ffffffff81108d99>] ? __do_fault+0x459/0x540
[241322.804651]  [<ffffffff81248256>] ? security_file_permission+0x16/0x20
[241322.804659]  [<ffffffff8113db5f>] do_readv_writev+0xcf/0x1f0
[241322.804667]  [<ffffffff8113dcc8>] vfs_writev+0x48/0x60
[241322.804675]  [<ffffffff8113ddf1>] sys_writev+0x51/0xb0
[241322.804682]  [<ffffffff8114f29c>] ? sys_poll+0x7c/0x110
[241322.804690]  [<ffffffff8100a072>] system_call_fastpath+0x16/0x1b
[241383.343089] usb 2-4: USB disconnect, address 23
[241383.343097] usb 2-4.1: USB disconnect, address 24
[241383.343103] usb 2-4.1.1: USB disconnect, address 25
[241442.810050] INFO: task thunderbird-bin:3159 blocked for more than 120 seconds.
[241442.810053] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[241442.810055] thunderbird-b D 00000001016faa2e     0  3159   3155 0x00000000
[241442.810059]  ffff88010500d3d8 0000000000000082 ffff88010500d368 0000000000015840
[241442.810062]  ffff88010500dfd8 0000000000015840 ffff88010500dfd8 ffff880096d496d0
[241442.810064]  0000000000015840 0000000000015840 ffff88010500dfd8 0000000000015840
[241442.810066] Call Trace:
[241442.810071]  [<ffffffff81032ca9>] ? default_spin_lock_flags+0x9/0x10
[241442.810075]  [<ffffffff810eda70>] ? sync_page+0x0/0x50
[241442.810078]  [<ffffffff81534327>] io_schedule+0x47/0x70
[241442.810080]  [<ffffffff810edaad>] sync_page+0x3d/0x50
[241442.810082]  [<ffffffff81534bdf>] __wait_on_bit+0x5f/0x90
[241442.810084]  [<ffffffff810edc63>] wait_on_page_bit+0x73/0x80
[241442.810087]  [<ffffffff8107a720>] ? wake_bit_function+0x0/0x40
[241442.810089]  [<ffffffff8153485d>] ? schedule_timeout+0x19d/0x310
[241442.810091]  [<ffffffff810fb266>] shrink_page_list+0x176/0x580
[241442.810094]  [<ffffffff8106b430>] ? process_timeout+0x0/0x10
[241442.810095]  [<ffffffff81032ca9>] ? default_spin_lock_flags+0x9/0x10
[241442.810097]  [<ffffffff8107a877>] ? finish_wait+0x67/0x90
[241442.810100]  [<ffffffff8110552e>] ? congestion_wait+0x7e/0x90
[241442.810101]  [<ffffffff8107a6e0>] ? autoremove_wake_function+0x0/0x40
[241442.810104]  [<ffffffff810fbd54>] shrink_inactive_list+0x6e4/0x7f0
[241442.810106]  [<ffffffff810512cc>] ? select_task_rq_fair+0x2fc/0x8e0
[241442.810108]  [<ffffffff810532c4>] ? check_preempt_wakeup+0x1b4/0x290
[241442.810110]  [<ffffffff8105197c>] ? try_to_wake_up+0xcc/0x400
[241442.810112]  [<ffffffff810fc1cb>] shrink_zone+0x36b/0x4b0
[241442.810115]  [<ffffffff810fc403>] do_try_to_free_pages+0xf3/0x440
[241442.810117]  [<ffffffff810fc8f8>] try_to_free_pages+0x68/0x70
[241442.810119]  [<ffffffff810f4428>] __alloc_pages_nodemask+0x3e8/0x6f0
[241442.810122]  [<ffffffff81045034>] ? scale_rt_power+0x24/0x70
[241442.810124]  [<ffffffff8112ae52>] kmalloc_large_node+0x62/0xb0
[241442.810126]  [<ffffffff8112e6fc>] __kmalloc_node_track_caller+0x13c/0x1f0
[241442.810129]  [<ffffffff81440a64>] ? sock_alloc_send_pskb+0x1d4/0x340
[241442.810131]  [<ffffffff81444bef>] ? __alloc_skb+0x4f/0x170
[241442.810133]  [<ffffffff81444c23>] __alloc_skb+0x83/0x170
[241442.810135]  [<ffffffff81440a64>] sock_alloc_send_pskb+0x1d4/0x340
[241442.810137]  [<ffffffff81440be5>] sock_alloc_send_skb+0x15/0x20
[241442.810140]  [<ffffffff814d8cb5>] unix_stream_sendmsg+0x275/0x3e0
[241442.810142]  [<ffffffff8143bfde>] sock_aio_write+0x14e/0x160
[241442.810144]  [<ffffffff81138b0e>] ? mem_cgroup_uncharge_swapcache+0x2e/0xb0
[241442.810146]  [<ffffffff8143be90>] ? sock_aio_write+0x0/0x160
[241442.810148]  [<ffffffff8113cad3>] do_sync_readv_writev+0xd3/0x110
[241442.810151]  [<ffffffff8111c475>] ? swap_entry_free+0x115/0x150
[241442.810154]  [<ffffffff81248256>] ? security_file_permission+0x16/0x20
[241442.810156]  [<ffffffff8113db5f>] do_readv_writev+0xcf/0x1f0
[241442.810158]  [<ffffffff8113dcc8>] vfs_writev+0x48/0x60
[241442.810160]  [<ffffffff8113ddf1>] sys_writev+0x51/0xb0
[241442.810162]  [<ffffffff8114f29c>] ? sys_poll+0x7c/0x110
[241442.810165]  [<ffffffff8100a072>] system_call_fastpath+0x16/0x1b
[241442.810181] INFO: task firefox-bin:12398 blocked for more than 120 seconds.
[241442.810183] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[241442.810184] firefox-bin   D 00000000ffffffff     0 12398  12394 0x00000000
[241442.810186]  ffff880078a592f8 0000000000000086 0000000000000400 0000000000015840
[241442.810189]  ffff880078a59fd8 0000000000015840 ffff880078a59fd8 ffff88004b395b40
[241442.810191]  0000000000015840 0000000000015840 ffff880078a59fd8 0000000000015840
[241442.810193] Call Trace:
[241442.810195]  [<ffffffff81032ca9>] ? default_spin_lock_flags+0x9/0x10
[241442.810197]  [<ffffffff810eda70>] ? sync_page+0x0/0x50
[241442.810199]  [<ffffffff81534327>] io_schedule+0x47/0x70
[241442.810201]  [<ffffffff810edaad>] sync_page+0x3d/0x50
[241442.810203]  [<ffffffff81534bdf>] __wait_on_bit+0x5f/0x90
[241442.810205]  [<ffffffff810edc63>] wait_on_page_bit+0x73/0x80
[241442.810207]  [<ffffffff8107a720>] ? wake_bit_function+0x0/0x40
[241442.810209]  [<ffffffff8153485d>] ? schedule_timeout+0x19d/0x310
[241442.810211]  [<ffffffff810fb266>] shrink_page_list+0x176/0x580
[241442.810213]  [<ffffffff8106b430>] ? process_timeout+0x0/0x10
[241442.810215]  [<ffffffff8110552e>] ? congestion_wait+0x7e/0x90
[241442.810216]  [<ffffffff8107a6e0>] ? autoremove_wake_function+0x0/0x40
[241442.810219]  [<ffffffff810fbd54>] shrink_inactive_list+0x6e4/0x7f0
[241442.810221]  [<ffffffff81047e18>] ? update_curr+0xf8/0x1e0
[241442.810224]  [<ffffffff8153664e>] ? _raw_spin_lock+0xe/0x20
[241442.810226]  [<ffffffff810483dd>] ? task_rq_lock+0x5d/0xa0
[241442.810228]  [<ffffffff8105197c>] ? try_to_wake_up+0xcc/0x400
[241442.810230]  [<ffffffff810fc1cb>] shrink_zone+0x36b/0x4b0
[241442.810232]  [<ffffffff810fc403>] do_try_to_free_pages+0xf3/0x440
[241442.810234]  [<ffffffff810fc8f8>] try_to_free_pages+0x68/0x70
[241442.810236]  [<ffffffff810f4428>] __alloc_pages_nodemask+0x3e8/0x6f0
[241442.810238]  [<ffffffff811255ca>] alloc_pages_current+0x9a/0x100
[241442.810240]  [<ffffffff8112b725>] new_slab+0x225/0x2c0
[241442.810242]  [<ffffffff8112d333>] __slab_alloc+0x163/0x500
[241442.810244]  [<ffffffff81440a64>] ? sock_alloc_send_pskb+0x1d4/0x340
[241442.810246]  [<ffffffff8112e671>] __kmalloc_node_track_caller+0xb1/0x1f0
[241442.810248]  [<ffffffff81440a64>] ? sock_alloc_send_pskb+0x1d4/0x340
[241442.810250]  [<ffffffff81444bef>] ? __alloc_skb+0x4f/0x170
[241442.810252]  [<ffffffff81444c23>] __alloc_skb+0x83/0x170
[241442.810254]  [<ffffffff81440a64>] sock_alloc_send_pskb+0x1d4/0x340
[241442.810256]  [<ffffffff81440be5>] sock_alloc_send_skb+0x15/0x20
[241442.810258]  [<ffffffff814d8cb5>] unix_stream_sendmsg+0x275/0x3e0
[241442.810260]  [<ffffffff810eda70>] ? sync_page+0x0/0x50
[241442.810262]  [<ffffffff8143bfde>] sock_aio_write+0x14e/0x160
[241442.810264]  [<ffffffff8143be90>] ? sock_aio_write+0x0/0x160
[241442.810266]  [<ffffffff8113cad3>] do_sync_readv_writev+0xd3/0x110
[241442.810268]  [<ffffffff810eda70>] ? sync_page+0x0/0x50
[241442.810270]  [<ffffffff81108d99>] ? __do_fault+0x459/0x540
[241442.810272]  [<ffffffff81248256>] ? security_file_permission+0x16/0x20
[241442.810274]  [<ffffffff8113db5f>] do_readv_writev+0xcf/0x1f0
[241442.810276]  [<ffffffff8113dcc8>] vfs_writev+0x48/0x60
[241442.810278]  [<ffffffff8113ddf1>] sys_writev+0x51/0xb0
[241442.810280]  [<ffffffff8114f29c>] ? sys_poll+0x7c/0x110
[241442.810282]  [<ffffffff8100a072>] system_call_fastpath+0x16/0x1b

-- 
Writing big files to NFS target causes system lock up
https://bugs.launchpad.net/bugs/561210
You received this bug notification because you are a member of Kernel
Bugs, which is subscribed to linux in ubuntu.