All of lore.kernel.org
 help / color / mirror / Atom feed
* btrfs deadlock (3.14 kernel)
@ 2014-03-21  6:06 Marc MERLIN
  2014-03-21 18:24 ` Josef Bacik
  0 siblings, 1 reply; 5+ messages in thread
From: Marc MERLIN @ 2014-03-21  6:06 UTC (permalink / raw)
  To: linux-btrfs

After 1.5 days of running, the machine I was doing btrfs receive on got
stuck with this (note, the traces are not all the same).

The machine is not dead, but any IO that goes through btrfs seems dead.

If you want Sysrq-W, let me know.

Is thre anything I can try to unwedge or prevent this problem next time I try?

Thanks,
Marc

[107280.560066] INFO: task btrfs-transacti:6728 blocked for more than 120 seconds.
[107280.560078]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[107280.560082] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[107280.560087] btrfs-transacti D ffff88007bb2e880     0  6728      2 0x00000080
[107280.560097]  ffff8800702d38d0 0000000000000046 ffff8800702d3fd8 ffff88007bb2e350
[107280.560109]  00000000000141c0 ffff88007bb2e350 ffff88007fc141c0 ffff88007bb2e350
[107280.560123]  ffff8800702d3970 ffffffff810fe5f2 0000000000000002 ffff8800702d38e0
[107280.560134] Call Trace:
[107280.560145]  [<ffffffff810fe5f2>] ? wait_on_page_read+0x3c/0x3c
[107280.560151]  [<ffffffff8160c331>] schedule+0x73/0x75
[107280.560157]  [<ffffffff8160c4d6>] io_schedule+0x60/0x7a
[107280.560162]  [<ffffffff810fe600>] sleep_on_page+0xe/0x12
[107280.560167]  [<ffffffff8160c768>] __wait_on_bit+0x48/0x7a
[107280.560187]  [<ffffffff810fe5a0>] wait_on_page_bit+0x7a/0x7c
[107280.560195]  [<ffffffff810850fd>] ? autoremove_wake_function+0x34/0x34
[107280.560201]  [<ffffffff81245ea2>] read_extent_buffer_pages+0x1bf/0x204
[107280.560207]  [<ffffffff81223942>] ? free_root_pointers+0x5b/0x5b
[107280.560214]  [<ffffffff81224644>] btree_read_extent_buffer_pages.constprop.45+0x66/0x100
[107280.560219]  [<ffffffff81225599>] read_tree_block+0x2f/0x47
[107280.560225]  [<ffffffff8120a930>] read_node_slot+0x85/0xb2
[107280.560236]  [<ffffffff8120ed52>] push_leaf_right+0x76/0x16b
[107280.560240]  [<ffffffff8120f593>] split_leaf+0xc5/0x567
[107280.560243]  [<ffffffff8120c189>] ? leaf_space_used+0xa9/0xd8
[107280.560248]  [<ffffffff812578cf>] ? btrfs_set_lock_blocking_rw+0x95/0xdf
[107280.560251]  [<ffffffff81210055>] btrfs_search_slot+0x620/0x6bb
[107280.560257]  [<ffffffff81211330>] btrfs_insert_empty_items+0x5d/0xa8
[107280.560261]  [<ffffffff8121ba41>] __btrfs_run_delayed_refs+0x6f1/0xbdf
[107280.560266]  [<ffffffff81016495>] ? native_sched_clock+0x34/0x36
[107280.560270]  [<ffffffff81015efa>] ? paravirt_sched_clock+0x9/0xd
[107280.560274]  [<ffffffff8121dac8>] btrfs_run_delayed_refs+0x81/0x18f
[107280.560278]  [<ffffffff8122ae40>] btrfs_commit_transaction+0x79/0x849
[107280.560282]  [<ffffffff812277ca>] transaction_kthread+0xf8/0x1ab
[107280.560286]  [<ffffffff812276d2>] ? btrfs_cleanup_transaction+0x43f/0x43f
[107280.560294]  [<ffffffff8106bc56>] kthread+0xae/0xb6
[107280.560298]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[107280.560302]  [<ffffffff816153fc>] ret_from_fork+0x7c/0xb0
[107280.560306]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[107280.560310] INFO: task btrfs:20144 blocked for more than 120 seconds.
[107280.560313]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[107280.560315] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[107280.560317] btrfs           D ffff88000043c540     0 20144  20139 0x00000080
[107280.560323]  ffff8800009ebb10 0000000000000082 ffff8800009ebfd8 ffff88000043c010
[107280.560331]  00000000000141c0 ffff88000043c010 ffff88007fc141c0 ffff88000043c010
[107280.560338]  ffff8800009ebbb0 0000000000000002 ffffffff810fe5f2 ffff8800009ebb20
[107280.560345] Call Trace:
[107280.560349]  [<ffffffff810fe5f2>] ? wait_on_page_read+0x3c/0x3c
[107280.560353]  [<ffffffff8160c331>] schedule+0x73/0x75
[107280.560356]  [<ffffffff8160c4d6>] io_schedule+0x60/0x7a
[107280.560360]  [<ffffffff810fe600>] sleep_on_page+0xe/0x12
[107280.560363]  [<ffffffff8160c866>] __wait_on_bit_lock+0x46/0x8a
[107280.560367]  [<ffffffff810fe6bb>] __lock_page+0x69/0x6b
[107280.560371]  [<ffffffff810850fd>] ? autoremove_wake_function+0x34/0x34
[107280.560375]  [<ffffffff81240beb>] lock_page+0x1e/0x21
[107280.560378]  [<ffffffff812446bc>] extent_write_cache_pages.isra.16.constprop.32+0x10e/0x2c6
[107280.560382]  [<ffffffff8110067f>] ? find_get_pages+0xef/0x104
[107280.560386]  [<ffffffff81244b1a>] extent_writepages+0x4b/0x5c
[107280.560390]  [<ffffffff8122eed5>] ? btrfs_submit_direct+0x3f4/0x3f4
[107280.560393]  [<ffffffff8122d5c7>] btrfs_writepages+0x28/0x2a
[107280.560398]  [<ffffffff81108e3b>] do_writepages+0x1e/0x2c
[107280.560402]  [<ffffffff810ffc03>] __filemap_fdatawrite_range+0x55/0x57
[107280.560405]  [<ffffffff810ffc36>] filemap_fdatawrite_range+0x13/0x15
[107280.560409]  [<ffffffff8123fab1>] btrfs_wait_ordered_range+0x88/0x11d
[107280.560413]  [<ffffffff8123324b>] btrfs_truncate+0x45/0x231
[107280.560416]  [<ffffffff81233cef>] btrfs_setattr+0x1a4/0x27c
[107280.560421]  [<ffffffff8116b33f>] notify_change+0x1e4/0x2c8
[107280.560427]  [<ffffffff81154045>] do_truncate+0x69/0x90
[107280.560431]  [<ffffffff81154156>] vfs_truncate+0xea/0x118
[107280.560435]  [<ffffffff811541ce>] do_sys_truncate+0x4a/0x86
[107280.560438]  [<ffffffff8115430e>] SyS_truncate+0xe/0x10
[107280.560442]  [<ffffffff816154ad>] system_call_fastpath+0x1a/0x1f
[107280.560449] INFO: task kworker/u8:0:22761 blocked for more than 120 seconds.
[107280.560452]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[107280.560454] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[107280.560456] kworker/u8:0    D ffff8800096ca940     0 22761      2 0x00000080
[107280.560465] Workqueue: writeback bdi_writeback_workfn (flush-btrfs-1)
[107280.560470]  ffff880023565a00 0000000000000046 ffff880023565fd8 ffff8800096ca410
[107280.560477]  00000000000141c0 ffff8800096ca410 ffff88007fc941c0 ffff8800096ca410
[107280.560484]  ffff880023565aa0 0000000000000002 ffffffff810fe5f2 ffff880023565a10
[107280.560495] Call Trace:
[107280.560499]  [<ffffffff810fe5f2>] ? wait_on_page_read+0x3c/0x3c
[107280.560503]  [<ffffffff8160c331>] schedule+0x73/0x75
[107280.560506]  [<ffffffff8160c4d6>] io_schedule+0x60/0x7a
[107280.560509]  [<ffffffff810fe600>] sleep_on_page+0xe/0x12
[107280.560513]  [<ffffffff8160c866>] __wait_on_bit_lock+0x46/0x8a
[107280.560517]  [<ffffffff810fe6bb>] __lock_page+0x69/0x6b
[107280.560521]  [<ffffffff810850fd>] ? autoremove_wake_function+0x34/0x34
[107280.560524]  [<ffffffff81240beb>] lock_page+0x1e/0x21
[107280.560528]  [<ffffffff812446bc>] extent_write_cache_pages.isra.16.constprop.32+0x10e/0x2c6
[107280.560532]  [<ffffffff81244b1a>] extent_writepages+0x4b/0x5c
[107280.560535]  [<ffffffff8122eed5>] ? btrfs_submit_direct+0x3f4/0x3f4
[107280.560539]  [<ffffffff81108e2c>] ? do_writepages+0xf/0x2c
[107280.560542]  [<ffffffff8122d5c7>] btrfs_writepages+0x28/0x2a
[107280.560546]  [<ffffffff81108e3b>] do_writepages+0x1e/0x2c
[107280.560550]  [<ffffffff8117683d>] __writeback_single_inode+0x7d/0x238
[107280.560553]  [<ffffffff811771c4>] writeback_sb_inodes+0x1eb/0x339
[107280.560557]  [<ffffffff81177386>] __writeback_inodes_wb+0x74/0xb7
[107280.560561]  [<ffffffff81177501>] wb_writeback+0x138/0x293
[107280.560565]  [<ffffffff81177a78>] bdi_writeback_workfn+0xc6/0x329
[107280.560569]  [<ffffffff8100e047>] ? load_TLS+0xb/0xf
[107280.560573]  [<ffffffff8106651d>] process_one_work+0x195/0x2d2
[107280.560577]  [<ffffffff81066a39>] worker_thread+0x136/0x205
[107280.560580]  [<ffffffff81066903>] ? rescuer_thread+0x27a/0x27a
[107280.560584]  [<ffffffff8106bc56>] kthread+0xae/0xb6
[107280.560588]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[107280.560592]  [<ffffffff816153fc>] ret_from_fork+0x7c/0xb0
[107280.560595]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[113640.560075] INFO: task btrfs-transacti:6728 blocked for more than 120 seconds.
[113640.560091]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[113640.560095] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[113640.560099] btrfs-transacti D ffff88007bb2e880     0  6728      2 0x00000080
[113640.560108]  ffff8800702d3840 0000000000000046 ffff8800702d3fd8 ffff88007bb2e350
[113640.560120]  00000000000141c0 ffff88007bb2e350 ffff88007fc941c0 ffff88007bb2e350
[113640.560131]  ffff8800702d38e0 ffffffff810fe5f2 0000000000000002 ffff8800702d3850
[113640.560146] Call Trace:
[113640.560157]  [<ffffffff810fe5f2>] ? wait_on_page_read+0x3c/0x3c
[113640.560164]  [<ffffffff8160c331>] schedule+0x73/0x75
[113640.560169]  [<ffffffff8160c4d6>] io_schedule+0x60/0x7a
[113640.560174]  [<ffffffff810fe600>] sleep_on_page+0xe/0x12
[113640.560185]  [<ffffffff8160c768>] __wait_on_bit+0x48/0x7a
[113640.560205]  [<ffffffff810fe5a0>] wait_on_page_bit+0x7a/0x7c
[113640.560212]  [<ffffffff810850fd>] ? autoremove_wake_function+0x34/0x34
[113640.560219]  [<ffffffff81245ea2>] read_extent_buffer_pages+0x1bf/0x204
[113640.560225]  [<ffffffff81223942>] ? free_root_pointers+0x5b/0x5b
[113640.560231]  [<ffffffff81224644>] btree_read_extent_buffer_pages.constprop.45+0x66/0x100
[113640.560236]  [<ffffffff81225599>] read_tree_block+0x2f/0x47
[113640.560247]  [<ffffffff8120a930>] read_node_slot+0x85/0xb2
[113640.560252]  [<ffffffff8120ed52>] push_leaf_right+0x76/0x16b
[113640.560256]  [<ffffffff8120f593>] split_leaf+0xc5/0x567
[113640.560260]  [<ffffffff8120c189>] ? leaf_space_used+0xa9/0xd8
[113640.560264]  [<ffffffff812578cf>] ? btrfs_set_lock_blocking_rw+0x95/0xdf
[113640.560268]  [<ffffffff81210055>] btrfs_search_slot+0x620/0x6bb
[113640.560272]  [<ffffffff81211330>] btrfs_insert_empty_items+0x5d/0xa8
[113640.560276]  [<ffffffff812170c6>] alloc_reserved_file_extent+0x95/0x233
[113640.560281]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[113640.560285]  [<ffffffff8121bd60>] __btrfs_run_delayed_refs+0xa10/0xbdf
[113640.560290]  [<ffffffff8121dac8>] btrfs_run_delayed_refs+0x81/0x18f
[113640.560294]  [<ffffffff8122ae40>] btrfs_commit_transaction+0x79/0x849
[113640.560298]  [<ffffffff812277ca>] transaction_kthread+0xf8/0x1ab
[113640.560302]  [<ffffffff812276d2>] ? btrfs_cleanup_transaction+0x43f/0x43f
[113640.560306]  [<ffffffff8106bc56>] kthread+0xae/0xb6
[113640.560310]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[113640.560315]  [<ffffffff816153fc>] ret_from_fork+0x7c/0xb0
[113640.560320]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[113760.560065] INFO: task btrfs:20144 blocked for more than 120 seconds.
[113760.560079]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[113760.560083] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[113760.560087] btrfs           D ffff88000043c540     0 20144  20139 0x00000080
[113760.560097]  ffff8800009ebb10 0000000000000082 ffff8800009ebfd8 ffff88000043c010
[113760.560114]  00000000000141c0 ffff88000043c010 ffff88007fc141c0 ffff88000043c010
[113760.560125]  ffff8800009ebbb0 ffffffff810fe5f2 0000000000000002 ffff8800009ebb20
[113760.560140] Call Trace:
[113760.560150]  [<ffffffff810fe5f2>] ? wait_on_page_read+0x3c/0x3c
[113760.560157]  [<ffffffff8160c331>] schedule+0x73/0x75
[113760.560164]  [<ffffffff8160c4d6>] io_schedule+0x60/0x7a
[113760.560170]  [<ffffffff810fe600>] sleep_on_page+0xe/0x12
[113760.560175]  [<ffffffff8160c768>] __wait_on_bit+0x48/0x7a
[113760.560180]  [<ffffffff810fe5a0>] wait_on_page_bit+0x7a/0x7c
[113760.560187]  [<ffffffff810850fd>] ? autoremove_wake_function+0x34/0x34
[113760.560193]  [<ffffffff81240a0d>] wait_on_page_writeback+0x16/0x18
[113760.560199]  [<ffffffff81244709>] extent_write_cache_pages.isra.16.constprop.32+0x15b/0x2c6
[113760.560205]  [<ffffffff8110067f>] ? find_get_pages+0xef/0x104
[113760.560213]  [<ffffffff81244b1a>] extent_writepages+0x4b/0x5c
[113760.560219]  [<ffffffff8122eed5>] ? btrfs_submit_direct+0x3f4/0x3f4
[113760.560224]  [<ffffffff8122d5c7>] btrfs_writepages+0x28/0x2a
[113760.560235]  [<ffffffff81108e3b>] do_writepages+0x1e/0x2c
[113760.560238]  [<ffffffff810ffc03>] __filemap_fdatawrite_range+0x55/0x57
[113760.560242]  [<ffffffff810ffc36>] filemap_fdatawrite_range+0x13/0x15
[113760.560246]  [<ffffffff8123fab1>] btrfs_wait_ordered_range+0x88/0x11d
[113760.560249]  [<ffffffff8123324b>] btrfs_truncate+0x45/0x231
[113760.560254]  [<ffffffff81233cef>] btrfs_setattr+0x1a4/0x27c
[113760.560259]  [<ffffffff8116b33f>] notify_change+0x1e4/0x2c8
[113760.560263]  [<ffffffff81154045>] do_truncate+0x69/0x90
[113760.560267]  [<ffffffff81154156>] vfs_truncate+0xea/0x118
[113760.560270]  [<ffffffff811541ce>] do_sys_truncate+0x4a/0x86
[113760.560274]  [<ffffffff8115430e>] SyS_truncate+0xe/0x10
[113760.560279]  [<ffffffff816154ad>] system_call_fastpath+0x1a/0x1f
[134520.560062] INFO: task btrfs:20144 blocked for more than 120 seconds.
[134520.560073]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[134520.560077] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[134520.560081] btrfs           D ffff88000043c540     0 20144  20139 0x00000080
[134520.560091]  ffff8800009ebd48 0000000000000082 ffff8800009ebfd8 ffff88000043c010
[134520.560107]  00000000000141c0 ffff88000043c010 ffff88001f3d92a0 ffff8800546391e8
[134520.560117]  0000000000000000 ffff880054639000 ffff88000c197420 ffff8800009ebd58
[134520.560128] Call Trace:
[134520.560138]  [<ffffffff8160c331>] schedule+0x73/0x75
[134520.560146]  [<ffffffff8122a5f9>] wait_current_trans.isra.15+0x98/0xf4
[134520.560153]  [<ffffffff810850c9>] ? finish_wait+0x65/0x65
[134520.560158]  [<ffffffff8122ba9e>] start_transaction+0x48e/0x4f2
[134520.560164]  [<ffffffff8122bb1d>] btrfs_start_transaction+0x1b/0x1d
[134520.560170]  [<ffffffff81233c8a>] btrfs_setattr+0x13f/0x27c
[134520.560176]  [<ffffffff8116b33f>] notify_change+0x1e4/0x2c8
[134520.560182]  [<ffffffff81154045>] do_truncate+0x69/0x90
[134520.560188]  [<ffffffff81154156>] vfs_truncate+0xea/0x118
[134520.560193]  [<ffffffff811541ce>] do_sys_truncate+0x4a/0x86
[134520.560199]  [<ffffffff8115430e>] SyS_truncate+0xe/0x10
[134520.560205]  [<ffffffff816154ad>] system_call_fastpath+0x1a/0x1f
[134640.560074] INFO: task btrfs:20144 blocked for more than 120 seconds.
[134640.560085]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[134640.560089] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[134640.560100] btrfs           D ffff88000043c540     0 20144  20139 0x00000080
[134640.560109]  ffff8800009ebd48 0000000000000082 ffff8800009ebfd8 ffff88000043c010
[134640.560121]  00000000000141c0 ffff88000043c010 ffff88001f3d92a0 ffff8800546391e8
[134640.560131]  0000000000000000 ffff880054639000 ffff88000c197420 ffff8800009ebd58
[134640.560142] Call Trace:
[134640.560151]  [<ffffffff8160c331>] schedule+0x73/0x75
[134640.560159]  [<ffffffff8122a5f9>] wait_current_trans.isra.15+0x98/0xf4
[134640.560166]  [<ffffffff810850c9>] ? finish_wait+0x65/0x65
[134640.560171]  [<ffffffff8122ba9e>] start_transaction+0x48e/0x4f2
[134640.560177]  [<ffffffff8122bb1d>] btrfs_start_transaction+0x1b/0x1d
[134640.560183]  [<ffffffff81233c8a>] btrfs_setattr+0x13f/0x27c
[134640.560191]  [<ffffffff8116b33f>] notify_change+0x1e4/0x2c8
[134640.560198]  [<ffffffff81154045>] do_truncate+0x69/0x90
[134640.560203]  [<ffffffff81154156>] vfs_truncate+0xea/0x118
[134640.560208]  [<ffffffff811541ce>] do_sys_truncate+0x4a/0x86
[134640.560214]  [<ffffffff8115430e>] SyS_truncate+0xe/0x10
[134640.560220]  [<ffffffff816154ad>] system_call_fastpath+0x1a/0x1f
[134760.560062] INFO: task btrfs:20144 blocked for more than 120 seconds.
[134760.560073]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[134760.560077] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[134760.560081] btrfs           D ffff88000043c540     0 20144  20139 0x00000080
[134760.560091]  ffff8800009ebd48 0000000000000082 ffff8800009ebfd8 ffff88000043c010
[134760.560102]  00000000000141c0 ffff88000043c010 ffff88001f3d92a0 ffff8800546391e8
[134760.560113]  0000000000000000 ffff880054639000 ffff88000c197420 ffff8800009ebd58
[134760.560124] Call Trace:
[134760.560133]  [<ffffffff8160c331>] schedule+0x73/0x75
[134760.560141]  [<ffffffff8122a5f9>] wait_current_trans.isra.15+0x98/0xf4
[134760.560148]  [<ffffffff810850c9>] ? finish_wait+0x65/0x65
[134760.560154]  [<ffffffff8122ba9e>] start_transaction+0x48e/0x4f2
[134760.560163]  [<ffffffff8122bb1d>] btrfs_start_transaction+0x1b/0x1d
[134760.560168]  [<ffffffff81233c8a>] btrfs_setattr+0x13f/0x27c
[134760.560174]  [<ffffffff8116b33f>] notify_change+0x1e4/0x2c8
[134760.560181]  [<ffffffff81154045>] do_truncate+0x69/0x90
[134760.560186]  [<ffffffff81154156>] vfs_truncate+0xea/0x118
[134760.560191]  [<ffffffff811541ce>] do_sys_truncate+0x4a/0x86
[134760.560197]  [<ffffffff8115430e>] SyS_truncate+0xe/0x10
[134760.560203]  [<ffffffff816154ad>] system_call_fastpath+0x1a/0x1f


-- 
"A mouse is a device used to point at the xterm you want to type in" - A.S.R.
Microsoft is to operating systems ....
                                      .... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/  

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: btrfs deadlock (3.14 kernel)
  2014-03-21  6:06 btrfs deadlock (3.14 kernel) Marc MERLIN
@ 2014-03-21 18:24 ` Josef Bacik
  2014-03-22  0:51   ` Marc MERLIN
  0 siblings, 1 reply; 5+ messages in thread
From: Josef Bacik @ 2014-03-21 18:24 UTC (permalink / raw)
  To: Marc MERLIN, linux-btrfs

On 03/21/2014 02:06 AM, Marc MERLIN wrote:
> After 1.5 days of running, the machine I was doing btrfs receive on got
> stuck with this (note, the traces are not all the same).
>
> The machine is not dead, but any IO that goes through btrfs seems dead.
>
> If you want Sysrq-W, let me know.
>
> Is thre anything I can try to unwedge or prevent this problem next time I try?
>

Sysrq+w would be nice so I can see what everybody is doing.  Thanks,

Josef


^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: btrfs deadlock (3.14 kernel)
  2014-03-21 18:24 ` Josef Bacik
@ 2014-03-22  0:51   ` Marc MERLIN
  2014-03-22  6:47     ` Marc MERLIN
  0 siblings, 1 reply; 5+ messages in thread
From: Marc MERLIN @ 2014-03-22  0:51 UTC (permalink / raw)
  To: Josef Bacik; +Cc: linux-btrfs

On Fri, Mar 21, 2014 at 02:24:45PM -0400, Josef Bacik wrote:
> >Is thre anything I can try to unwedge or prevent this problem next time I 
> >try?
> 
> Sysrq+w would be nice so I can see what everybody is doing.  Thanks,

Sure thing. There you go
http://marc.merlins.org/tmp/sysreq-w-btrfs.txt
(too big to paste on the list)

Marc
-- 
"A mouse is a device used to point at the xterm you want to type in" - A.S.R.
Microsoft is to operating systems ....
                                      .... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/  

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: btrfs deadlock (3.14 kernel)
  2014-03-22  0:51   ` Marc MERLIN
@ 2014-03-22  6:47     ` Marc MERLIN
  2014-03-22 21:24       ` Marc MERLIN
  0 siblings, 1 reply; 5+ messages in thread
From: Marc MERLIN @ 2014-03-22  6:47 UTC (permalink / raw)
  To: Josef Bacik; +Cc: linux-btrfs

On Fri, Mar 21, 2014 at 05:51:23PM -0700, Marc MERLIN wrote:
> On Fri, Mar 21, 2014 at 02:24:45PM -0400, Josef Bacik wrote:
> > >Is thre anything I can try to unwedge or prevent this problem next time I 
> > >try?
> > 
> > Sysrq+w would be nice so I can see what everybody is doing.  Thanks,
> 
> Sure thing. There you go
> http://marc.merlins.org/tmp/sysreq-w-btrfs.txt
> (too big to paste on the list)

Later on, on the same filesystem, I removed a drive, added another one, and did a balance.
It's still running as of now, but I'm getting some more blocked messages if that helps.

polgara:/mnt/btrfs_backupcopy# btrfs balance start . 
[ 2478.807643] BTRFS info (device dm-8): relocating block group 610296528896 flags 132
[ 2533.497984] BTRFS info (device dm-8): found 10755 extents
[ 2534.171970] BTRFS info (device dm-8): relocating block group 600632852480 flags 129
[ 2605.128529] perf samples too long (2510 > 2500), lowering kernel.perf_event_max_sample_rate to 50000
[ 2658.269914] BTRFS info (device dm-8): found 152415 extents
[ 2720.016436] BTRFS info (device dm-8): found 152414 extents
[ 2725.331007] BTRFS info (device dm-8): relocating block group 590969176064 flags 129
[ 2893.950429] BTRFS info (device dm-8): found 61122 extents
[ 2918.439790] BTRFS info (device dm-8): found 61122 extents
[ 2919.622722] BTRFS info (device dm-8): relocating block group 589761216512 flags 132
[ 3024.003479] BTRFS info (device dm-8): found 40540 extents
[ 3024.809596] BTRFS info (device dm-8): relocating block group 588553256960 flags 132
[ 3190.396757] BTRFS info (device dm-8): found 65999 extents
[ 3190.998052] BTRFS info (device dm-8): relocating block group 587345297408 flags 132
[ 3373.859850] BTRFS info (device dm-8): found 68408 extents
[ 3374.492637] BTRFS info (device dm-8): relocating block group 586137337856 flags 132
[ 3541.988379] BTRFS info (device dm-8): found 62940 extents
[ 3542.747725] BTRFS info (device dm-8): relocating block group 576473661440 flags 129
[ 3811.800110] BTRFS info (device dm-8): found 847969 extents
[ 4150.174138] BTRFS info (device dm-8): found 847969 extents
[ 4187.253411] BTRFS info (device dm-8): relocating block group 566809985024 flags 129
[ 4363.966721] BTRFS info (device dm-8): found 171089 extents
[ 4402.735354] BTRFS info (device dm-8): found 171089 extents
[ 4404.593423] BTRFS info (device dm-8): relocating block group 557146308608 flags 129
[ 4589.878118] BTRFS info (device dm-8): found 39967 extents
[ 4601.308021] BTRFS info (device dm-8): found 39967 extents
[ 4602.115166] BTRFS info (device dm-8): relocating block group 547482632192 flags 129
[ 5040.560066] INFO: task btrfs:7773 blocked for more than 120 seconds.
[ 5040.560073]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[ 5040.560075] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 5040.560078] btrfs           D ffff88005f096780     0  7773   6854 0x00000080
[ 5040.560083]  ffff88005bf07940 0000000000000086 ffff88005bf07fd8 ffff88005f096250
[ 5040.560089]  00000000000141c0 ffff88005f096250 ffff88007fc141c0 ffff88005f096250
[ 5040.560094]  ffff88005bf079e0 0000000000000002 ffffffff810fe5f2 ffff88005bf07950
[ 5040.560099] Call Trace:
[ 5040.560108]  [<ffffffff810fe5f2>] ? wait_on_page_read+0x3c/0x3c
[ 5040.560113]  [<ffffffff8160c331>] schedule+0x73/0x75
[ 5040.560117]  [<ffffffff8160c4d6>] io_schedule+0x60/0x7a
[ 5040.560121]  [<ffffffff810fe600>] sleep_on_page+0xe/0x12
[ 5040.560124]  [<ffffffff8160c866>] __wait_on_bit_lock+0x46/0x8a
[ 5040.560128]  [<ffffffff810fe6bb>] __lock_page+0x69/0x6b
[ 5040.560134]  [<ffffffff810850fd>] ? autoremove_wake_function+0x34/0x34
[ 5040.560138]  [<ffffffff810fec39>] ? find_get_page+0x69/0x75
[ 5040.560142]  [<ffffffff810feeb9>] lock_page+0x19/0x1c
[ 5040.560145]  [<ffffffff810fef15>] find_lock_page+0x33/0x55
[ 5040.560150]  [<ffffffff81266d4a>] relocate_file_extent_cluster+0x117/0x32c
[ 5040.560154]  [<ffffffff81266ff1>] relocate_data_extent+0x92/0xa7
[ 5040.560158]  [<ffffffff8126aa58>] relocate_block_group+0x2b2/0x49a
[ 5040.560162]  [<ffffffff8123f526>] ? btrfs_wait_ordered_roots+0x107/0x140
[ 5040.560166]  [<ffffffff8126ad98>] btrfs_relocate_block_group+0x158/0x26a
[ 5040.560171]  [<ffffffff81249544>] btrfs_relocate_chunk.isra.23+0x5c/0x5e8
[ 5040.560176]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[ 5040.560180]  [<ffffffff812452f7>] ? free_extent_buffer+0x8a/0x8d
[ 5040.560184]  [<ffffffff8124bdca>] btrfs_balance+0x9b6/0xb74
[ 5040.560188]  [<ffffffff8113f328>] ? trace_kmalloc+0x15/0x74
[ 5040.560193]  [<ffffffff812523b9>] btrfs_ioctl_balance+0x23e/0x2b7
[ 5040.560197]  [<ffffffff81255fa9>] btrfs_ioctl+0x1223/0x24b1
[ 5040.560202]  [<ffffffff811610e4>] ? path_openat+0x237/0x4de
[ 5040.560206]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[ 5040.560210]  [<ffffffff81611e15>] ? __do_page_fault+0x330/0x3df
[ 5040.560215]  [<ffffffff81125bc6>] ? vma_link+0x74/0x93
[ 5040.560219]  [<ffffffff81163b16>] do_vfs_ioctl+0x3d2/0x41d
[ 5040.560223]  [<ffffffff81163bb8>] SyS_ioctl+0x57/0x82
[ 5040.560227]  [<ffffffff81611ed2>] ? do_page_fault+0xe/0x10
[ 5040.560236]  [<ffffffff816154ad>] system_call_fastpath+0x1a/0x1f
[ 5160.560062] INFO: task btrfs:7773 blocked for more than 120 seconds.
[ 5160.560068]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[ 5160.560071] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 5160.560073] btrfs           D ffff88005f096780     0  7773   6854 0x00000080
[ 5160.560079]  ffff88005bf07940 0000000000000086 ffff88005bf07fd8 ffff88005f096250
[ 5160.560085]  00000000000141c0 ffff88005f096250 ffff88007fc141c0 ffff88005f096250
[ 5160.560089]  ffff88005bf079e0 0000000000000002 ffffffff810fe5f2 ffff88005bf07950
[ 5160.560094] Call Trace:
[ 5160.560103]  [<ffffffff810fe5f2>] ? wait_on_page_read+0x3c/0x3c
[ 5160.560108]  [<ffffffff8160c331>] schedule+0x73/0x75
[ 5160.560112]  [<ffffffff8160c4d6>] io_schedule+0x60/0x7a
[ 5160.560116]  [<ffffffff810fe600>] sleep_on_page+0xe/0x12
[ 5160.560120]  [<ffffffff8160c866>] __wait_on_bit_lock+0x46/0x8a
[ 5160.560124]  [<ffffffff810fe6bb>] __lock_page+0x69/0x6b
[ 5160.560129]  [<ffffffff810850fd>] ? autoremove_wake_function+0x34/0x34
[ 5160.560133]  [<ffffffff810fec39>] ? find_get_page+0x69/0x75
[ 5160.560137]  [<ffffffff810feeb9>] lock_page+0x19/0x1c
[ 5160.560141]  [<ffffffff810fef15>] find_lock_page+0x33/0x55
[ 5160.560146]  [<ffffffff81266d4a>] relocate_file_extent_cluster+0x117/0x32c
[ 5160.560150]  [<ffffffff81266ff1>] relocate_data_extent+0x92/0xa7
[ 5160.560153]  [<ffffffff8126aa58>] relocate_block_group+0x2b2/0x49a
[ 5160.560158]  [<ffffffff8123f526>] ? btrfs_wait_ordered_roots+0x107/0x140
[ 5160.560162]  [<ffffffff8126ad98>] btrfs_relocate_block_group+0x158/0x26a
[ 5160.560166]  [<ffffffff81249544>] btrfs_relocate_chunk.isra.23+0x5c/0x5e8
[ 5160.560171]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[ 5160.560175]  [<ffffffff812452f7>] ? free_extent_buffer+0x8a/0x8d
[ 5160.560179]  [<ffffffff8124bdca>] btrfs_balance+0x9b6/0xb74
[ 5160.560184]  [<ffffffff8113f328>] ? trace_kmalloc+0x15/0x74
[ 5160.560188]  [<ffffffff812523b9>] btrfs_ioctl_balance+0x23e/0x2b7
[ 5160.560193]  [<ffffffff81255fa9>] btrfs_ioctl+0x1223/0x24b1
[ 5160.560197]  [<ffffffff811610e4>] ? path_openat+0x237/0x4de
[ 5160.560201]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[ 5160.560205]  [<ffffffff81611e15>] ? __do_page_fault+0x330/0x3df
[ 5160.560210]  [<ffffffff81125bc6>] ? vma_link+0x74/0x93
[ 5160.560213]  [<ffffffff81163b16>] do_vfs_ioctl+0x3d2/0x41d
[ 5160.560218]  [<ffffffff81163bb8>] SyS_ioctl+0x57/0x82
[ 5160.560222]  [<ffffffff81611ed2>] ? do_page_fault+0xe/0x10
[ 5160.560226]  [<ffffffff816154ad>] system_call_fastpath+0x1a/0x1f
[ 5280.560028] INFO: task kworker/0:1:30 blocked for more than 120 seconds.
[ 5280.560034]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[ 5280.560036] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 5280.560039] kworker/0:1     D ffff88007c376600     0    30      2 0x00000000
[ 5280.560044]  ffff88007c379b70 0000000000000046 ffff88007c379fd8 ffff88007c3760d0
[ 5280.560050]  00000000000141c0 ffff88007c3760d0 ffff880079e4e530 ffff880079e4e534
[ 5280.560055]  ffff88007c3760d0 ffff880079e4e538 00000000ffffffff ffff88007c379b80
[ 5280.560060] Call Trace:
[ 5280.560068]  [<ffffffff8160c331>] schedule+0x73/0x75
[ 5280.560073]  [<ffffffff8160c5f2>] schedule_preempt_disabled+0x18/0x24
[ 5280.560077]  [<ffffffff8160d129>] __mutex_lock_slowpath+0x158/0x1cf
[ 5280.560082]  [<ffffffff8160ea3d>] ? _raw_spin_unlock_irqrestore+0x1f/0x32
[ 5280.560086]  [<ffffffff8160d1b7>] mutex_lock+0x17/0x27
[ 5280.560091]  [<ffffffff81100016>] generic_file_aio_write+0x43/0xc3
[ 5280.560097]  [<ffffffff811bb398>] ext4_file_write+0x394/0x3c0
[ 5280.560102]  [<ffffffff8107c349>] ? account_entity_enqueue+0x5a/0x8b
[ 5280.560106]  [<ffffffff8107e7da>] ? check_preempt_wakeup+0x128/0x1f9
[ 5280.560109]  [<ffffffff8107c826>] ? hrtick_update+0x1b/0x4d
[ 5280.560113]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[ 5280.560118]  [<ffffffff81154e98>] do_sync_write+0x59/0x78
[ 5280.560123]  [<ffffffff810b35bf>] do_acct_process+0x30b/0x393
[ 5280.560128]  [<ffffffff81066903>] ? rescuer_thread+0x27a/0x27a
[ 5280.560133]  [<ffffffff810b3bef>] acct_process+0x77/0x92
[ 5280.560137]  [<ffffffff810520f4>] do_exit+0x3a0/0x938
[ 5280.560141]  [<ffffffff8160ea6c>] ? _raw_spin_unlock_irq+0x1c/0x2f
[ 5280.560145]  [<ffffffff81066944>] ? worker_thread+0x41/0x205
[ 5280.560148]  [<ffffffff81066903>] ? rescuer_thread+0x27a/0x27a
[ 5280.560152]  [<ffffffff8106bc5e>] kthread+0xb6/0xb6
[ 5280.560157]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[ 5280.560161]  [<ffffffff816153fc>] ret_from_fork+0x7c/0xb0
[ 5280.560165]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[ 5280.560174] INFO: task kworker/u9:2:282 blocked for more than 120 seconds.
[ 5280.560176]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[ 5280.560179] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 5280.560181] kworker/u9:2    D ffff88007b446540     0   282      2 0x00000000
[ 5280.560185]  ffff88007a463b70 0000000000000046 ffff88007a463fd8 ffff88007b446010
[ 5280.560190]  00000000000141c0 ffff88007b446010 ffff880079e4e530 ffff880079e4e534
[ 5280.560195]  ffff88007b446010 ffff880079e4e538 00000000ffffffff ffff88007a463b80
[ 5280.560200] Call Trace:
[ 5280.560204]  [<ffffffff8160c331>] schedule+0x73/0x75
[ 5280.560208]  [<ffffffff8160c5f2>] schedule_preempt_disabled+0x18/0x24
[ 5280.560212]  [<ffffffff8160d129>] __mutex_lock_slowpath+0x158/0x1cf
[ 5280.560238]  [<ffffffffa0142a76>] ? mvs_queue_command+0x3d/0x29b [mvsas]
[ 5280.560241]  [<ffffffff8160d1b7>] mutex_lock+0x17/0x27
[ 5280.560244]  [<ffffffff81100016>] generic_file_aio_write+0x43/0xc3
[ 5280.560247]  [<ffffffff811bb398>] ext4_file_write+0x394/0x3c0
[ 5280.560249]  [<ffffffff8107c349>] ? account_entity_enqueue+0x5a/0x8b
[ 5280.560252]  [<ffffffff8107e7da>] ? check_preempt_wakeup+0x128/0x1f9
[ 5280.560254]  [<ffffffff8107c826>] ? hrtick_update+0x1b/0x4d
[ 5280.560257]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[ 5280.560260]  [<ffffffff81154e98>] do_sync_write+0x59/0x78
[ 5280.560263]  [<ffffffff810b35bf>] do_acct_process+0x30b/0x393
[ 5280.560266]  [<ffffffff81066903>] ? rescuer_thread+0x27a/0x27a
[ 5280.560268]  [<ffffffff810b3bef>] acct_process+0x77/0x92
[ 5280.560271]  [<ffffffff810520f4>] do_exit+0x3a0/0x938
[ 5280.560274]  [<ffffffff8160ea6c>] ? _raw_spin_unlock_irq+0x1c/0x2f
[ 5280.560276]  [<ffffffff81066944>] ? worker_thread+0x41/0x205
[ 5280.560278]  [<ffffffff81066903>] ? rescuer_thread+0x27a/0x27a
[ 5280.560281]  [<ffffffff8106bc5e>] kthread+0xb6/0xb6
[ 5280.560284]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[ 5280.560287]  [<ffffffff816153fc>] ret_from_fork+0x7c/0xb0
[ 5280.560289]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[ 5280.560321] INFO: task kworker/0:0:7518 blocked for more than 120 seconds.
[ 5280.560323]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[ 5280.560325] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 5280.560326] kworker/0:0     D ffff880060524b40     0  7518      2 0x00000080
[ 5280.560329]  ffff880060527b70 0000000000000046 ffff880060527fd8 ffff880060524610
[ 5280.560332]  00000000000141c0 ffff880060524610 ffff880079e4e530 ffff880079e4e534
[ 5280.560335]  ffff880060524610 ffff880079e4e538 00000000ffffffff ffff880060527b80
[ 5280.560339] Call Trace:
[ 5280.560342]  [<ffffffff8160c331>] schedule+0x73/0x75
[ 5280.560344]  [<ffffffff8160c5f2>] schedule_preempt_disabled+0x18/0x24
[ 5280.560347]  [<ffffffff8160d129>] __mutex_lock_slowpath+0x158/0x1cf
[ 5280.560350]  [<ffffffff8160d1b7>] mutex_lock+0x17/0x27
[ 5280.560352]  [<ffffffff81100016>] generic_file_aio_write+0x43/0xc3
[ 5280.560355]  [<ffffffff811bb398>] ext4_file_write+0x394/0x3c0
[ 5280.560358]  [<ffffffff8107c349>] ? account_entity_enqueue+0x5a/0x8b
[ 5280.560361]  [<ffffffff8107e7da>] ? check_preempt_wakeup+0x128/0x1f9
[ 5280.560363]  [<ffffffff8107c826>] ? hrtick_update+0x1b/0x4d
[ 5280.560366]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[ 5280.560369]  [<ffffffff81154e98>] do_sync_write+0x59/0x78
[ 5280.560371]  [<ffffffff810b35bf>] do_acct_process+0x30b/0x393
[ 5280.560374]  [<ffffffff81066903>] ? rescuer_thread+0x27a/0x27a
[ 5280.560377]  [<ffffffff810b3bef>] acct_process+0x77/0x92
[ 5280.560380]  [<ffffffff810520f4>] do_exit+0x3a0/0x938
[ 5280.560382]  [<ffffffff8160ea6c>] ? _raw_spin_unlock_irq+0x1c/0x2f
[ 5280.560385]  [<ffffffff81066944>] ? worker_thread+0x41/0x205
[ 5280.560387]  [<ffffffff81066903>] ? rescuer_thread+0x27a/0x27a
[ 5280.560390]  [<ffffffff8106bc5e>] kthread+0xb6/0xb6
[ 5280.560393]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[ 5280.560395]  [<ffffffff816153fc>] ret_from_fork+0x7c/0xb0
[ 5280.560398]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[ 5280.560402] INFO: task kworker/0:3:7702 blocked for more than 120 seconds.
[ 5280.560403]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[ 5280.560405] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 5280.560406] kworker/0:3     D ffff88005f31cb80     0  7702      2 0x00000080
[ 5280.560409]  ffff88005f31fb70 0000000000000046 ffff88005f31ffd8 ffff88005f31c650
[ 5280.560412]  00000000000141c0 ffff88005f31c650 ffff880079e4e530 ffff880079e4e534
[ 5280.560415]  ffff88005f31c650 ffff880079e4e538 00000000ffffffff ffff88005f31fb80
[ 5280.560419] Call Trace:
[ 5280.560422]  [<ffffffff8160c331>] schedule+0x73/0x75
[ 5280.560424]  [<ffffffff8160c5f2>] schedule_preempt_disabled+0x18/0x24
[ 5280.560427]  [<ffffffff8160d129>] __mutex_lock_slowpath+0x158/0x1cf
[ 5280.560430]  [<ffffffff8160d1b7>] mutex_lock+0x17/0x27
[ 5280.560432]  [<ffffffff81100016>] generic_file_aio_write+0x43/0xc3
[ 5280.560435]  [<ffffffff811bb398>] ext4_file_write+0x394/0x3c0
[ 5280.560438]  [<ffffffff8107c349>] ? account_entity_enqueue+0x5a/0x8b
[ 5280.560440]  [<ffffffff8107e7da>] ? check_preempt_wakeup+0x128/0x1f9
[ 5280.560443]  [<ffffffff8107c826>] ? hrtick_update+0x1b/0x4d
[ 5280.560446]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[ 5280.560448]  [<ffffffff81154e98>] do_sync_write+0x59/0x78
[ 5280.560451]  [<ffffffff810b35bf>] do_acct_process+0x30b/0x393
[ 5280.560454]  [<ffffffff81066903>] ? rescuer_thread+0x27a/0x27a
[ 5280.560457]  [<ffffffff810b3bef>] acct_process+0x77/0x92
[ 5280.560459]  [<ffffffff810520f4>] do_exit+0x3a0/0x938
[ 5280.560462]  [<ffffffff8160ea6c>] ? _raw_spin_unlock_irq+0x1c/0x2f
[ 5280.560464]  [<ffffffff81066944>] ? worker_thread+0x41/0x205
[ 5280.560467]  [<ffffffff81066903>] ? rescuer_thread+0x27a/0x27a
[ 5280.560469]  [<ffffffff8106bc5e>] kthread+0xb6/0xb6
[ 5280.560472]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[ 5280.560475]  [<ffffffff816153fc>] ret_from_fork+0x7c/0xb0
[ 5280.560477]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[ 5280.560480] INFO: task kworker/1:4:7705 blocked for more than 120 seconds.
[ 5280.560482]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[ 5280.560483] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 5280.560484] kworker/1:4     D ffff88005e0acc40     0  7705      2 0x00000080
[ 5280.560487]  ffff88005e0afb70 0000000000000046 ffff88005e0affd8 ffff88005e0ac710
[ 5280.560490]  00000000000141c0 ffff88005e0ac710 ffff880079e4e530 ffff880079e4e534
[ 5280.560494]  ffff88005e0ac710 ffff880079e4e538 00000000ffffffff ffff88005e0afb80
[ 5280.560497] Call Trace:
[ 5280.560500]  [<ffffffff8160c331>] schedule+0x73/0x75
[ 5280.560502]  [<ffffffff8160c5f2>] schedule_preempt_disabled+0x18/0x24
[ 5280.560505]  [<ffffffff8160d129>] __mutex_lock_slowpath+0x158/0x1cf
[ 5280.560508]  [<ffffffff8160d1b7>] mutex_lock+0x17/0x27
[ 5280.560510]  [<ffffffff81100016>] generic_file_aio_write+0x43/0xc3
[ 5280.560513]  [<ffffffff811bb398>] ext4_file_write+0x394/0x3c0
[ 5280.560516]  [<ffffffff8107c349>] ? account_entity_enqueue+0x5a/0x8b
[ 5280.560519]  [<ffffffff8107e7da>] ? check_preempt_wakeup+0x128/0x1f9
[ 5280.560521]  [<ffffffff8107c826>] ? hrtick_update+0x1b/0x4d
[ 5280.560524]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[ 5280.560527]  [<ffffffff81154e98>] do_sync_write+0x59/0x78
[ 5280.560529]  [<ffffffff810b35bf>] do_acct_process+0x30b/0x393
[ 5280.560532]  [<ffffffff81066903>] ? rescuer_thread+0x27a/0x27a
[ 5280.560535]  [<ffffffff810b3bef>] acct_process+0x77/0x92
[ 5280.560537]  [<ffffffff810520f4>] do_exit+0x3a0/0x938
[ 5280.560540]  [<ffffffff8160ea6c>] ? _raw_spin_unlock_irq+0x1c/0x2f
[ 5280.560543]  [<ffffffff81066944>] ? worker_thread+0x41/0x205
[ 5280.560545]  [<ffffffff81066903>] ? rescuer_thread+0x27a/0x27a
[ 5280.560548]  [<ffffffff8106bc5e>] kthread+0xb6/0xb6
[ 5280.560550]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[ 5280.560553]  [<ffffffff816153fc>] ret_from_fork+0x7c/0xb0
[ 5280.560556]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[ 5280.560559] INFO: task btrfs:7773 blocked for more than 120 seconds.
[ 5280.560560]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[ 5280.560562] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 5280.560563] btrfs           D ffff88005f096780     0  7773   6854 0x00000080
[ 5280.560566]  ffff88005bf07940 0000000000000086 ffff88005bf07fd8 ffff88005f096250
[ 5280.560569]  00000000000141c0 ffff88005f096250 ffff88007fc141c0 ffff88005f096250
[ 5280.560572]  ffff88005bf079e0 0000000000000002 ffffffff810fe5f2 ffff88005bf07950
[ 5280.560576] Call Trace:
[ 5280.560579]  [<ffffffff810fe5f2>] ? wait_on_page_read+0x3c/0x3c
[ 5280.560581]  [<ffffffff8160c331>] schedule+0x73/0x75
[ 5280.560584]  [<ffffffff8160c4d6>] io_schedule+0x60/0x7a
[ 5280.560586]  [<ffffffff810fe600>] sleep_on_page+0xe/0x12
[ 5280.560589]  [<ffffffff8160c866>] __wait_on_bit_lock+0x46/0x8a
[ 5280.560592]  [<ffffffff810fe6bb>] __lock_page+0x69/0x6b
[ 5280.560595]  [<ffffffff810850fd>] ? autoremove_wake_function+0x34/0x34
[ 5280.560598]  [<ffffffff810fec39>] ? find_get_page+0x69/0x75
[ 5280.560600]  [<ffffffff810feeb9>] lock_page+0x19/0x1c
[ 5280.560603]  [<ffffffff810fef15>] find_lock_page+0x33/0x55
[ 5280.560606]  [<ffffffff81266d4a>] relocate_file_extent_cluster+0x117/0x32c
[ 5280.560609]  [<ffffffff81266ff1>] relocate_data_extent+0x92/0xa7
[ 5280.560611]  [<ffffffff8126aa58>] relocate_block_group+0x2b2/0x49a
[ 5280.560614]  [<ffffffff8123f526>] ? btrfs_wait_ordered_roots+0x107/0x140
[ 5280.560617]  [<ffffffff8126ad98>] btrfs_relocate_block_group+0x158/0x26a
[ 5280.560620]  [<ffffffff81249544>] btrfs_relocate_chunk.isra.23+0x5c/0x5e8
[ 5280.560623]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[ 5280.560626]  [<ffffffff812452f7>] ? free_extent_buffer+0x8a/0x8d
[ 5280.560628]  [<ffffffff8124bdca>] btrfs_balance+0x9b6/0xb74
[ 5280.560632]  [<ffffffff8113f328>] ? trace_kmalloc+0x15/0x74
[ 5280.560635]  [<ffffffff812523b9>] btrfs_ioctl_balance+0x23e/0x2b7
[ 5280.560638]  [<ffffffff81255fa9>] btrfs_ioctl+0x1223/0x24b1
[ 5280.560641]  [<ffffffff811610e4>] ? path_openat+0x237/0x4de
[ 5280.560643]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[ 5280.560646]  [<ffffffff81611e15>] ? __do_page_fault+0x330/0x3df
[ 5280.560649]  [<ffffffff81125bc6>] ? vma_link+0x74/0x93
[ 5280.560652]  [<ffffffff81163b16>] do_vfs_ioctl+0x3d2/0x41d
[ 5280.560655]  [<ffffffff81163bb8>] SyS_ioctl+0x57/0x82
[ 5280.560658]  [<ffffffff81611ed2>] ? do_page_fault+0xe/0x10
[ 5280.560660]  [<ffffffff816154ad>] system_call_fastpath+0x1a/0x1f
[ 5280.560663] INFO: task kworker/0:5:7774 blocked for more than 120 seconds.
[ 5280.560664]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[ 5280.560666] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 5280.560667] kworker/0:5     D ffff88005f7fa840     0  7774      2 0x00000080
[ 5280.560670]  ffff88005be7db70 0000000000000046 ffff88005be7dfd8 ffff88005f7fa310
[ 5280.560673]  00000000000141c0 ffff88005f7fa310 ffff880079e4e530 ffff880079e4e534
[ 5280.560676]  ffff88005f7fa310 ffff880079e4e538 00000000ffffffff ffff88005be7db80
[ 5280.560679] Call Trace:
[ 5280.560682]  [<ffffffff8160c331>] schedule+0x73/0x75
[ 5280.560685]  [<ffffffff8160c5f2>] schedule_preempt_disabled+0x18/0x24
[ 5280.560688]  [<ffffffff8160d129>] __mutex_lock_slowpath+0x158/0x1cf
[ 5280.560690]  [<ffffffff8160d1b7>] mutex_lock+0x17/0x27
[ 5280.560693]  [<ffffffff81100016>] generic_file_aio_write+0x43/0xc3
[ 5280.560696]  [<ffffffff811bb398>] ext4_file_write+0x394/0x3c0
[ 5280.560699]  [<ffffffff8107c349>] ? account_entity_enqueue+0x5a/0x8b
[ 5280.560701]  [<ffffffff8107e7da>] ? check_preempt_wakeup+0x128/0x1f9
[ 5280.560704]  [<ffffffff8107c826>] ? hrtick_update+0x1b/0x4d
[ 5280.560706]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[ 5280.560709]  [<ffffffff81154e98>] do_sync_write+0x59/0x78
[ 5280.560712]  [<ffffffff810b35bf>] do_acct_process+0x30b/0x393
[ 5280.560715]  [<ffffffff81066903>] ? rescuer_thread+0x27a/0x27a
[ 5280.560718]  [<ffffffff810b3bef>] acct_process+0x77/0x92
[ 5280.560720]  [<ffffffff810520f4>] do_exit+0x3a0/0x938
[ 5280.560723]  [<ffffffff8160ea6c>] ? _raw_spin_unlock_irq+0x1c/0x2f
[ 5280.560725]  [<ffffffff81066944>] ? worker_thread+0x41/0x205
[ 5280.560728]  [<ffffffff81066903>] ? rescuer_thread+0x27a/0x27a
[ 5280.560730]  [<ffffffff8106bc5e>] kthread+0xb6/0xb6
[ 5280.560733]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[ 5280.560736]  [<ffffffff816153fc>] ret_from_fork+0x7c/0xb0
[ 5280.560739]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[ 5280.560741] INFO: task kworker/1:8:7797 blocked for more than 120 seconds.
[ 5280.560743]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[ 5280.560744] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 5280.560745] kworker/1:8     D ffff8800544ba5c0     0  7797      2 0x00000080
[ 5280.560748]  ffff880050c2db70 0000000000000046 ffff880050c2dfd8 ffff8800544ba090
[ 5280.560751]  00000000000141c0 ffff8800544ba090 ffff880079e4e530 ffff880079e4e534
[ 5280.560754]  ffff8800544ba090 ffff880079e4e538 00000000ffffffff ffff880050c2db80
[ 5280.560758] Call Trace:
[ 5280.560761]  [<ffffffff8160c331>] schedule+0x73/0x75
[ 5280.560763]  [<ffffffff8160c5f2>] schedule_preempt_disabled+0x18/0x24
[ 5280.560766]  [<ffffffff8160d129>] __mutex_lock_slowpath+0x158/0x1cf
[ 5280.560769]  [<ffffffff814a9598>] ? ata_qc_issue+0x291/0x2f1
[ 5280.560772]  [<ffffffff8160d1b7>] mutex_lock+0x17/0x27
[ 5280.560775]  [<ffffffff81100016>] generic_file_aio_write+0x43/0xc3
[ 5280.560778]  [<ffffffff811bb398>] ext4_file_write+0x394/0x3c0
[ 5280.560780]  [<ffffffff8107c349>] ? account_entity_enqueue+0x5a/0x8b
[ 5280.560783]  [<ffffffff8107e7da>] ? check_preempt_wakeup+0x128/0x1f9
[ 5280.560785]  [<ffffffff8107c826>] ? hrtick_update+0x1b/0x4d
[ 5280.560788]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[ 5280.560791]  [<ffffffff81154e98>] do_sync_write+0x59/0x78
[ 5280.560794]  [<ffffffff810b35bf>] do_acct_process+0x30b/0x393
[ 5280.560796]  [<ffffffff81066903>] ? rescuer_thread+0x27a/0x27a
[ 5280.560799]  [<ffffffff810b3bef>] acct_process+0x77/0x92
[ 5280.560802]  [<ffffffff810520f4>] do_exit+0x3a0/0x938
[ 5280.560804]  [<ffffffff8160ea6c>] ? _raw_spin_unlock_irq+0x1c/0x2f
[ 5280.560807]  [<ffffffff81066944>] ? worker_thread+0x41/0x205
[ 5280.560809]  [<ffffffff81066903>] ? rescuer_thread+0x27a/0x27a
[ 5280.560812]  [<ffffffff8106bc5e>] kthread+0xb6/0xb6
[ 5280.560815]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[ 5280.560817]  [<ffffffff816153fc>] ret_from_fork+0x7c/0xb0
[ 5280.560820]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[ 5338.750443] BTRFS info (device dm-8): found 453260 extents
[ 5427.502521] BTRFS info (device dm-8): found 453260 extents
[ 5437.708990] BTRFS info (device dm-8): relocating block group 537818955776 flags 129

Best,
Marc
-- 
"A mouse is a device used to point at the xterm you want to type in" - A.S.R.
Microsoft is to operating systems ....
                                      .... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/                         | PGP 1024R/763BE901

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: btrfs deadlock (3.14 kernel)
  2014-03-22  6:47     ` Marc MERLIN
@ 2014-03-22 21:24       ` Marc MERLIN
  0 siblings, 0 replies; 5+ messages in thread
From: Marc MERLIN @ 2014-03-22 21:24 UTC (permalink / raw)
  To: Josef Bacik; +Cc: linux-btrfs

On Fri, Mar 21, 2014 at 11:47:18PM -0700, Marc MERLIN wrote:
> On Fri, Mar 21, 2014 at 05:51:23PM -0700, Marc MERLIN wrote:
> > On Fri, Mar 21, 2014 at 02:24:45PM -0400, Josef Bacik wrote:
> > > >Is thre anything I can try to unwedge or prevent this problem next time I 
> > > >try?
> > > 
> > > Sysrq+w would be nice so I can see what everybody is doing.  Thanks,
> > 
> > Sure thing. There you go
> > http://marc.merlins.org/tmp/sysreq-w-btrfs.txt
> > (too big to paste on the list)
> 
> Later on, on the same filesystem, I removed a drive, added another one, and did a balance.
> It's still running as of now, but I'm getting some more blocked messages if that helps.
> 

Mmmh, I have another list of blocks today that may be a different sequence
The system is pretty hozed after this, it was able to write it to syslog
after minutes of hanging, but now I'm not sure I'm going to get anything
more out of it without a reboot.

Let me know if you need more.

Thanks,
Marc

[23049.987258] BTRFS info (device dm-9): found 30649 extents
[23064.281199] BTRFS info (device dm-9): found 30649 extents
[23065.579373] BTRFS info (device dm-9): relocating block group 783034744832 flags 129
[23235.361816] BTRFS info (device dm-9): found 61920 extents
[23252.948433] BTRFS info (device dm-9): found 61920 extents
[23254.622630] BTRFS info (device dm-9): relocating block group 772163108864 flags 129
[23520.560068] INFO: task btrfs-transacti:7371 blocked for more than 120 seconds.
[23520.560084]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[23520.560089] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[23520.560092] btrfs-transacti D ffff88006e326880     0  7371      2 0x00000080
[23520.560102]  ffff880059c53bc0 0000000000000046 ffff880059c53fd8 ffff88006e326350
[23520.560113]  00000000000141c0 ffff88006e326350 ffff88007fc141c0 ffff88006e326350
[23520.560124]  ffff880059c53c60 ffffffff810fe5f2 0000000000000002 ffff880059c53bd0
[23520.560141] Call Trace:
[23520.560151]  [<ffffffff810fe5f2>] ? wait_on_page_read+0x3c/0x3c
[23520.560158]  [<ffffffff8160c331>] schedule+0x73/0x75
[23520.560163]  [<ffffffff8160c4d6>] io_schedule+0x60/0x7a
[23520.560169]  [<ffffffff810fe600>] sleep_on_page+0xe/0x12
[23520.560174]  [<ffffffff8160c768>] __wait_on_bit+0x48/0x7a
[23520.560179]  [<ffffffff810fe5a0>] wait_on_page_bit+0x7a/0x7c
[23520.560186]  [<ffffffff810850fd>] ? autoremove_wake_function+0x34/0x34
[23520.560192]  [<ffffffff81109c3d>] ? pagevec_lookup_tag+0x21/0x29
[23520.560198]  [<ffffffff810ff090>] filemap_fdatawait_range+0x7e/0x126
[23520.560205]  [<ffffffff8122abde>] btrfs_wait_marked_extents+0x7d/0xcd
[23520.560211]  [<ffffffff8122aca3>] btrfs_write_and_wait_transaction+0x75/0x87
[23520.560217]  [<ffffffff8122b423>] btrfs_commit_transaction+0x65c/0x849
[23520.560223]  [<ffffffff810850c9>] ? finish_wait+0x65/0x65
[23520.560228]  [<ffffffff812277ca>] transaction_kthread+0xf8/0x1ab
[23520.560238]  [<ffffffff812276d2>] ? btrfs_cleanup_transaction+0x43f/0x43f
[23520.560242]  [<ffffffff8106bc56>] kthread+0xae/0xb6
[23520.560246]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[23520.560251]  [<ffffffff816153fc>] ret_from_fork+0x7c/0xb0
[23520.560254]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[23640.564048] INFO: task jbd2/sda6-8:1018 blocked for more than 120 seconds.
[23640.564065]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[23640.564069] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[23640.564072] jbd2/sda6-8     D ffff88007a2f0a80     0  1018      2 0x00000000
[23640.564082]  ffff880078c99cc0 0000000000000046 ffff880078c99fd8 ffff88007a2f0550
[23640.564094]  00000000000141c0 ffff88007a2f0550 ffff880078c99d88 ffff88006c6ad4a0
[23640.564104]  ffff880078c99da0 ffff880078db3800 ffff88006c6ad440 ffff880078c99cd0
[23640.564120] Call Trace:
[23640.564130]  [<ffffffff8160c331>] schedule+0x73/0x75
[23640.564137]  [<ffffffff811f9317>] jbd2_journal_commit_transaction+0x270/0x14cf
[23640.564143]  [<ffffffff8107d766>] ? update_entity_load_avg+0x270/0x27f
[23640.564150]  [<ffffffff81015eed>] ? paravirt_read_tsc+0x9/0xd
[23640.564156]  [<ffffffff81015efa>] ? paravirt_sched_clock+0x9/0xd
[23640.564162]  [<ffffffff8107b383>] ? sched_clock_cpu+0xb5/0xd7
[23640.564168]  [<ffffffff810850c9>] ? finish_wait+0x65/0x65
[23640.564174]  [<ffffffff81059bd4>] ? lock_timer_base.isra.24+0x2b/0x4f
[23640.564180]  [<ffffffff81059cab>] ? try_to_del_timer_sync+0x55/0x5f
[23640.564186]  [<ffffffff811fea06>] kjournald2+0xc0/0x232
[23640.564191]  [<ffffffff810850c9>] ? finish_wait+0x65/0x65
[23640.564196]  [<ffffffff811fe946>] ? get_slab+0x47/0x47
[23640.564202]  [<ffffffff8106bc56>] kthread+0xae/0xb6
[23640.564208]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[23640.564215]  [<ffffffff816153fc>] ret_from_fork+0x7c/0xb0
[23640.564220]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[23640.564248] INFO: task nscd:3917 blocked for more than 120 seconds.
[23640.564251]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[23640.564253] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[23640.564255] nscd            D ffff88006d2e2c40     0  3917      1 0x00000080
[23640.564263]  ffff88006bd07aa8 0000000000000086 ffff88006bd07fd8 ffff88006d2e2710
[23640.564275]  00000000000141c0 ffff88006d2e2710 ffff880078db3800 0000000000000000
[23640.564284]  ffff880078db3870 0000000000015afd ffff88006c6ad440 ffff88006bd07ab8
[23640.564291] Call Trace:
[23640.564295]  [<ffffffff8160c331>] schedule+0x73/0x75
[23640.564299]  [<ffffffff811f6932>] wait_transaction_locked+0x8e/0xa7
[23640.564303]  [<ffffffff810850c9>] ? finish_wait+0x65/0x65
[23640.564307]  [<ffffffff811f6ecf>] start_this_handle+0x2e6/0x4bf
[23640.564312]  [<ffffffff8114118d>] ? kmem_cache_alloc+0xe3/0x161
[23640.564315]  [<ffffffff811f716c>] jbd2__journal_start+0xc4/0x19d
[23640.564320]  [<ffffffff811c4183>] ? ext4_dirty_inode+0x2a/0x59
[23640.564324]  [<ffffffff811e43d6>] __ext4_journal_start_sb+0x97/0xbb
[23640.564328]  [<ffffffff811c4183>] ext4_dirty_inode+0x2a/0x59
[23640.564333]  [<ffffffff81176cb6>] __mark_inode_dirty+0x68/0x23b
[23640.564337]  [<ffffffff8116997d>] update_time+0xab/0xb4
[23640.564343]  [<ffffffff8116a3df>] file_update_time+0x96/0xb2
[23640.564347]  [<ffffffff811c434a>] ext4_page_mkwrite+0x56/0x2ae
[23640.564351]  [<ffffffff811205d3>] do_wp_page+0x175/0x574
[23640.564355]  [<ffffffff81122b43>] handle_mm_fault+0x8df/0x9b0
[23640.564359]  [<ffffffff8111f4d1>] ? tlb_flush_mmu+0x58/0x75
[23640.564363]  [<ffffffff81611e78>] __do_page_fault+0x393/0x3df
[23640.564366]  [<ffffffff8113f9d1>] ? __cache_free.isra.39+0x1b4/0x1c3
[23640.564371]  [<ffffffff8131e669>] ? __percpu_counter_add+0x71/0x8b
[23640.564375]  [<ffffffff8112513a>] ? vm_acct_memory+0x19/0x1b
[23640.564379]  [<ffffffff81126d39>] ? do_munmap+0x2bb/0x2dc
[23640.564383]  [<ffffffff81611ed2>] do_page_fault+0xe/0x10
[23640.564386]  [<ffffffff8160f478>] page_fault+0x28/0x30
[23640.564390] INFO: task nscd:3918 blocked for more than 120 seconds.
[23640.564392]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[23640.564395] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[23640.564397] nscd            D ffff88006cc64880     0  3918      1 0x00000080
[23640.564403]  ffff88006bd2dde0 0000000000000086 ffff88006bd2dfd8 ffff88006cc64350
[23640.564410]  00000000000141c0 ffff88006cc64350 ffff88007b1fd460 ffff88006cc64350
[23640.564419]  ffffffff00000001 ffff88007b1fd468 ffffffffffffffff ffff88006bd2ddf0
[23640.564427] Call Trace:
[23640.564431]  [<ffffffff8160c331>] schedule+0x73/0x75
[23640.564435]  [<ffffffff8160e20a>] rwsem_down_write_failed+0x118/0x19a
[23640.564440]  [<ffffffff8130af63>] call_rwsem_down_write_failed+0x13/0x20
[23640.564444]  [<ffffffff81296fb8>] ? cap_mmap_addr+0x49/0x49
[23640.564448]  [<ffffffff8160dcb9>] ? down_write+0x24/0x26
[23640.564453]  [<ffffffff811166e2>] vm_mmap_pgoff+0x5a/0xaf
[23640.564456]  [<ffffffff8116bd38>] ? __fget+0x6f/0x79
[23640.564460]  [<ffffffff81126704>] SyS_mmap_pgoff+0x188/0x1d4
[23640.564464]  [<ffffffff8101368a>] SyS_mmap+0x1b/0x27
[23640.564468]  [<ffffffff816154ad>] system_call_fastpath+0x1a/0x1f
[23640.564483] INFO: task btrfs-transacti:7371 blocked for more than 120 seconds.
[23640.564486]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[23640.564488] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[23640.564491] btrfs-transacti D ffff88006e326880     0  7371      2 0x00000080
[23640.564496]  ffff880059c53bc0 0000000000000046 ffff880059c53fd8 ffff88006e326350
[23640.564504]  00000000000141c0 ffff88006e326350 ffff88007fc141c0 ffff88006e326350
[23640.564511]  ffff880059c53c60 ffffffff810fe5f2 0000000000000002 ffff880059c53bd0
[23640.564518] Call Trace:
[23640.564522]  [<ffffffff810fe5f2>] ? wait_on_page_read+0x3c/0x3c
[23640.564526]  [<ffffffff8160c331>] schedule+0x73/0x75
[23640.564529]  [<ffffffff8160c4d6>] io_schedule+0x60/0x7a
[23640.564533]  [<ffffffff810fe600>] sleep_on_page+0xe/0x12
[23640.564536]  [<ffffffff8160c768>] __wait_on_bit+0x48/0x7a
[23640.564540]  [<ffffffff810fe5a0>] wait_on_page_bit+0x7a/0x7c
[23640.564544]  [<ffffffff810850fd>] ? autoremove_wake_function+0x34/0x34
[23640.564548]  [<ffffffff81109c3d>] ? pagevec_lookup_tag+0x21/0x29
[23640.564552]  [<ffffffff810ff090>] filemap_fdatawait_range+0x7e/0x126
[23640.564557]  [<ffffffff8122abde>] btrfs_wait_marked_extents+0x7d/0xcd
[23640.564561]  [<ffffffff8122aca3>] btrfs_write_and_wait_transaction+0x75/0x87
[23640.564565]  [<ffffffff8122b423>] btrfs_commit_transaction+0x65c/0x849
[23640.564568]  [<ffffffff810850c9>] ? finish_wait+0x65/0x65
[23640.564572]  [<ffffffff812277ca>] transaction_kthread+0xf8/0x1ab
[23640.564576]  [<ffffffff812276d2>] ? btrfs_cleanup_transaction+0x43f/0x43f
[23640.564580]  [<ffffffff8106bc56>] kthread+0xae/0xb6
[23640.564584]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[23640.564588]  [<ffffffff816153fc>] ret_from_fork+0x7c/0xb0
[23640.564591]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[23640.564595] INFO: task btrfs-endio-wri:7519 blocked for more than 120 seconds.
[23640.564597]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[23640.564600] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[23640.564602] btrfs-endio-wri D ffff88004d62c6c0     0  7519      2 0x00000080
[23640.564608]  ffff88001181bb70 0000000000000046 ffff88001181bfd8 ffff88004d62c190
[23640.564615]  00000000000141c0 ffff88004d62c190 ffff88007be0e5b0 ffff88007be0e5b4
[23640.564623]  ffff88004d62c190 ffff88007be0e5b8 00000000ffffffff ffff88001181bb80
[23640.564630] Call Trace:
[23640.564634]  [<ffffffff8160c331>] schedule+0x73/0x75
[23640.564637]  [<ffffffff8160c5f2>] schedule_preempt_disabled+0x18/0x24
[23640.564641]  [<ffffffff8160d129>] __mutex_lock_slowpath+0x158/0x1cf
[23640.564645]  [<ffffffff8160d1b7>] mutex_lock+0x17/0x27
[23640.564649]  [<ffffffff81100016>] generic_file_aio_write+0x43/0xc3
[23640.564655]  [<ffffffff811bb398>] ext4_file_write+0x394/0x3c0
[23640.564659]  [<ffffffff8108911d>] ? cpuacct_charge+0x4c/0x53
[23640.564662]  [<ffffffff8107e08c>] ? update_curr+0xcd/0x13f
[23640.564666]  [<ffffffff8107ce76>] ? update_stats_wait_end+0x7c/0xdb
[23640.564670]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[23640.564674]  [<ffffffff81154e98>] do_sync_write+0x59/0x78
[23640.564679]  [<ffffffff810b35bf>] do_acct_process+0x30b/0x393
[23640.564683]  [<ffffffff812505d7>] ? btrfs_queue_worker+0x283/0x283
[23640.564687]  [<ffffffff810b3bef>] acct_process+0x77/0x92
[23640.564693]  [<ffffffff810520f4>] do_exit+0x3a0/0x938
[23640.564696]  [<ffffffff812505d7>] ? btrfs_queue_worker+0x283/0x283
[23640.564700]  [<ffffffff8106bc5e>] kthread+0xb6/0xb6
[23640.564704]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[23640.564707]  [<ffffffff816153fc>] ret_from_fork+0x7c/0xb0
[23640.564711]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[23640.564715] INFO: task btrfs:18919 blocked for more than 120 seconds.
[23640.564718]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[23640.564720] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[23640.564722] btrfs           D ffff88007b500840     0 18919   6108 0x00000084
[23640.564728]  ffff880031ee9150 0000000000000086 ffff880031ee9fd8 ffff88005c348210
[23640.564735]  00000000000141c0 ffff88005c348210 ffff88007fc141c0 ffff88005c348210
[23640.564741]  ffff880031ee91f0 ffffffff810fe5f2 0000000000000002 ffff880031ee9160
[23640.564748] Call Trace:
[23640.564752]  [<ffffffff810fe5f2>] ? wait_on_page_read+0x3c/0x3c
[23640.564756]  [<ffffffff8160c331>] schedule+0x73/0x75
[23640.564759]  [<ffffffff8160c4d6>] io_schedule+0x60/0x7a
[23640.564762]  [<ffffffff810fe600>] sleep_on_page+0xe/0x12
[23640.564766]  [<ffffffff8160c768>] __wait_on_bit+0x48/0x7a
[23640.564770]  [<ffffffff810fe5a0>] wait_on_page_bit+0x7a/0x7c
[23640.564773]  [<ffffffff810850fd>] ? autoremove_wake_function+0x34/0x34
[23640.564777]  [<ffffffff81245ea2>] read_extent_buffer_pages+0x1bf/0x204
[23640.564781]  [<ffffffff81223942>] ? free_root_pointers+0x5b/0x5b
[23640.564785]  [<ffffffff81224644>] btree_read_extent_buffer_pages.constprop.45+0x66/0x100
[23640.564789]  [<ffffffff81225599>] read_tree_block+0x2f/0x47
[23640.564794]  [<ffffffff8120e6e8>] read_block_for_search.isra.26+0x24a/0x287
[23640.564797]  [<ffffffff8120ff29>] btrfs_search_slot+0x4f4/0x6bb
[23640.564801]  [<ffffffff81140d66>] ? ____cache_alloc_node+0xf1/0x134
[23640.564805]  [<ffffffff81220d07>] btrfs_lookup_csum+0x5e/0xfb
[23640.564809]  [<ffffffff81220fdb>] __btrfs_lookup_bio_sums+0x237/0x3fe
[23640.564813]  [<ffffffff812213a8>] btrfs_lookup_bio_sums+0x16/0x18
[23640.564816]  [<ffffffff8122cfde>] btrfs_submit_bio_hook+0xc5/0x152
[23640.564829]  [<ffffffffa048c6fd>] ? dm_merge_bvec+0xaa/0xca [dm_mod]
[23640.564833]  [<ffffffff8124035b>] submit_one_bio+0x8a/0xc0
[23640.564837]  [<ffffffff81242b68>] submit_extent_page.isra.19+0x9d/0x182
[23640.564841]  [<ffffffff81243c5c>] __do_readpage+0x439/0x4ef
[23640.564844]  [<ffffffff81242ee5>] ? repair_eb_io_failure+0x93/0x93
[23640.564848]  [<ffffffff8122eed5>] ? btrfs_submit_direct+0x3f4/0x3f4
[23640.564852]  [<ffffffff81243e9e>] __do_contiguous_readpages.constprop.23+0xc3/0xe3
[23640.564856]  [<ffffffff8122eed5>] ? btrfs_submit_direct+0x3f4/0x3f4
[23640.564859]  [<ffffffff81243fb8>] __extent_readpages.constprop.22+0xfa/0x109
[23640.564863]  [<ffffffff8110a8d9>] ? __lru_cache_add+0x5d/0x73
[23640.564867]  [<ffffffff8122eed5>] ? btrfs_submit_direct+0x3f4/0x3f4
[23640.564870]  [<ffffffff81244c39>] extent_readpages+0x10e/0x1a4
[23640.564874]  [<ffffffff8122d59d>] btrfs_readpages+0x1f/0x21
[23640.564878]  [<ffffffff8110916a>] __do_page_cache_readahead+0x15c/0x1f8
[23640.564882]  [<ffffffff8110944b>] ra_submit+0x21/0x25
[23640.564885]  [<ffffffff81109667>] ondemand_readahead+0x218/0x240
[23640.564889]  [<ffffffff810fec39>] ? find_get_page+0x69/0x75
[23640.564893]  [<ffffffff811096cc>] page_cache_sync_readahead+0x3d/0x3f
[23640.564897]  [<ffffffff81266d69>] relocate_file_extent_cluster+0x136/0x32c
[23640.564901]  [<ffffffff81266ff1>] relocate_data_extent+0x92/0xa7
[23640.564904]  [<ffffffff8126aa58>] relocate_block_group+0x2b2/0x49a
[23640.564908]  [<ffffffff8123f526>] ? btrfs_wait_ordered_roots+0x107/0x140
[23640.564912]  [<ffffffff8126ad98>] btrfs_relocate_block_group+0x158/0x26a
[23640.564916]  [<ffffffff81249544>] btrfs_relocate_chunk.isra.23+0x5c/0x5e8
[23640.564920]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[23640.564923]  [<ffffffff812452f7>] ? free_extent_buffer+0x8a/0x8d
[23640.564927]  [<ffffffff8124bdca>] btrfs_balance+0x9b6/0xb74
[23640.564931]  [<ffffffff812523b9>] btrfs_ioctl_balance+0x23e/0x2b7
[23640.564935]  [<ffffffff81255fa9>] btrfs_ioctl+0x1223/0x24b1
[23640.564938]  [<ffffffff811610e4>] ? path_openat+0x237/0x4de
[23640.564942]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[23640.564946]  [<ffffffff81611e15>] ? __do_page_fault+0x330/0x3df
[23640.564949]  [<ffffffff81125bc6>] ? vma_link+0x74/0x93
[23640.564953]  [<ffffffff81163b16>] do_vfs_ioctl+0x3d2/0x41d
[23640.564956]  [<ffffffff81163bb8>] SyS_ioctl+0x57/0x82
[23640.564960]  [<ffffffff81611ed2>] ? do_page_fault+0xe/0x10
[23640.564964]  [<ffffffff816154ad>] system_call_fastpath+0x1a/0x1f
[23640.564967] INFO: task btrfs-worker-3:18929 blocked for more than 120 seconds.
[23640.564969]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[23640.564972] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[23640.564974] btrfs-worker-3  D ffff88004dc08b40     0 18929      2 0x00000080
[23640.564979]  ffff88000d2b1b70 0000000000000046 ffff88000d2b1fd8 ffff88004dc08610
[23640.564986]  00000000000141c0 ffff88004dc08610 ffff88007be0e5b0 ffff88007be0e5b4
[23640.564993]  ffff88004dc08610 ffff88007be0e5b8 00000000ffffffff ffff88000d2b1b80
[23640.565000] Call Trace:
[23640.565004]  [<ffffffff8160c331>] schedule+0x73/0x75
[23640.565007]  [<ffffffff8160c5f2>] schedule_preempt_disabled+0x18/0x24
[23640.565011]  [<ffffffff8160d129>] __mutex_lock_slowpath+0x158/0x1cf
[23640.565015]  [<ffffffff8160d1b7>] mutex_lock+0x17/0x27
[23640.565018]  [<ffffffff81100016>] generic_file_aio_write+0x43/0xc3
[23640.565022]  [<ffffffff811bb398>] ext4_file_write+0x394/0x3c0
[23640.565026]  [<ffffffff81015eed>] ? paravirt_read_tsc+0x9/0xd
[23640.565030]  [<ffffffff81016495>] ? native_sched_clock+0x34/0x36
[23640.565033]  [<ffffffff8107ce76>] ? update_stats_wait_end+0x7c/0xdb
[23640.565037]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[23640.565041]  [<ffffffff81154e98>] do_sync_write+0x59/0x78
[23640.565045]  [<ffffffff810b35bf>] do_acct_process+0x30b/0x393
[23640.565049]  [<ffffffff812505d7>] ? btrfs_queue_worker+0x283/0x283
[23640.565052]  [<ffffffff810b3bef>] acct_process+0x77/0x92
[23640.565056]  [<ffffffff810520f4>] do_exit+0x3a0/0x938
[23640.565059]  [<ffffffff812505d7>] ? btrfs_queue_worker+0x283/0x283
[23640.565063]  [<ffffffff8106bc5e>] kthread+0xb6/0xb6
[23640.565067]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[23640.565070]  [<ffffffff816153fc>] ret_from_fork+0x7c/0xb0
[23640.565074]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[23640.565079] INFO: task btrfs-endio-4:19488 blocked for more than 120 seconds.
[23640.565083]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[23640.565086] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[23640.565088] btrfs-endio-4   D ffff88003c1e2580     0 19488      2 0x00000080
[23640.565093]  ffff880067cb3b70 0000000000000046 ffff880067cb3fd8 ffff88003c1e2050
[23640.565102]  00000000000141c0 ffff88003c1e2050 ffff88007be0e5b0 ffff88007be0e5b4
[23640.565109]  ffff88003c1e2050 ffff88007be0e5b8 00000000ffffffff ffff880067cb3b80
[23640.565116] Call Trace:
[23640.565120]  [<ffffffff8160c331>] schedule+0x73/0x75
[23640.565123]  [<ffffffff8160c5f2>] schedule_preempt_disabled+0x18/0x24
[23640.565127]  [<ffffffff8160d129>] __mutex_lock_slowpath+0x158/0x1cf
[23640.565131]  [<ffffffff8160d1b7>] mutex_lock+0x17/0x27
[23640.565135]  [<ffffffff81100016>] generic_file_aio_write+0x43/0xc3
[23640.565139]  [<ffffffff811bb398>] ext4_file_write+0x394/0x3c0
[23640.565142]  [<ffffffff8108911d>] ? cpuacct_charge+0x4c/0x53
[23640.565145]  [<ffffffff8107e08c>] ? update_curr+0xcd/0x13f
[23640.565149]  [<ffffffff8107ce76>] ? update_stats_wait_end+0x7c/0xdb
[23640.565153]  [<ffffffff8130536e>] ? rb_erase+0x28e/0x295
[23640.565156]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[23640.565160]  [<ffffffff81154e98>] do_sync_write+0x59/0x78
[23640.565164]  [<ffffffff810b35bf>] do_acct_process+0x30b/0x393
[23640.565168]  [<ffffffff812505d7>] ? btrfs_queue_worker+0x283/0x283
[23640.565171]  [<ffffffff810b3bef>] acct_process+0x77/0x92
[23640.565175]  [<ffffffff810520f4>] do_exit+0x3a0/0x938
[23640.565178]  [<ffffffff812505d7>] ? btrfs_queue_worker+0x283/0x283
[23640.565182]  [<ffffffff8106bc5e>] kthread+0xb6/0xb6
[23640.565186]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[23640.565189]  [<ffffffff816153fc>] ret_from_fork+0x7c/0xb0
[23640.565193]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[23640.565196] INFO: task btrfs-endio-wri:19490 blocked for more than 120 seconds.
[23640.565199]       Not tainted 3.14.0-rc5-amd64-i915-preempt-20140216c #1
[23640.565201] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[23640.565203] btrfs-endio-wri D ffff8800006c05c0     0 19490      2 0x00000080
[23640.565209]  ffff880000b47b70 0000000000000046 ffff880000b47fd8 ffff8800006c0090
[23640.565216]  00000000000141c0 ffff8800006c0090 ffff88007be0e5b0 ffff88007be0e5b4
[23640.565222]  ffff8800006c0090 ffff88007be0e5b8 00000000ffffffff ffff880000b47b80
[23640.565229] Call Trace:
[23640.565233]  [<ffffffff8160c331>] schedule+0x73/0x75
[23640.565237]  [<ffffffff8160c5f2>] schedule_preempt_disabled+0x18/0x24
[23640.565240]  [<ffffffff8160d129>] __mutex_lock_slowpath+0x158/0x1cf
[23640.565244]  [<ffffffff8160d1b7>] mutex_lock+0x17/0x27
[23640.565248]  [<ffffffff81100016>] generic_file_aio_write+0x43/0xc3
[23640.565251]  [<ffffffff811bb398>] ext4_file_write+0x394/0x3c0
[23640.565255]  [<ffffffff8108911d>] ? cpuacct_charge+0x4c/0x53
[23640.565258]  [<ffffffff8107ce76>] ? update_stats_wait_end+0x7c/0xdb
[23640.565262]  [<ffffffff8160ea0b>] ? _raw_spin_unlock+0x17/0x2a
[23640.565266]  [<ffffffff81154e98>] do_sync_write+0x59/0x78
[23640.565270]  [<ffffffff810b35bf>] do_acct_process+0x30b/0x393
[23640.565275]  [<ffffffff812505d7>] ? btrfs_queue_worker+0x283/0x283
[23640.565279]  [<ffffffff810b3bef>] acct_process+0x77/0x92
[23640.565284]  [<ffffffff810520f4>] do_exit+0x3a0/0x938
[23640.565288]  [<ffffffff812505d7>] ? btrfs_queue_worker+0x283/0x283
[23640.565291]  [<ffffffff8106bc5e>] kthread+0xb6/0xb6
[23640.565295]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61
[23640.565299]  [<ffffffff816153fc>] ret_from_fork+0x7c/0xb0
[23640.565303]  [<ffffffff8106bba8>] ? __kthread_parkme+0x61/0x61

-- 
"A mouse is a device used to point at the xterm you want to type in" - A.S.R.
Microsoft is to operating systems ....
                                      .... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/  

^ permalink raw reply	[flat|nested] 5+ messages in thread

end of thread, other threads:[~2014-03-22 21:24 UTC | newest]

Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2014-03-21  6:06 btrfs deadlock (3.14 kernel) Marc MERLIN
2014-03-21 18:24 ` Josef Bacik
2014-03-22  0:51   ` Marc MERLIN
2014-03-22  6:47     ` Marc MERLIN
2014-03-22 21:24       ` Marc MERLIN

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.