All of lore.kernel.org
 help / color / mirror / Atom feed
* btrfs hung tasks
@ 2013-10-12 13:36 John Drescher
  2013-10-13 15:50 ` Hugo Mills
  0 siblings, 1 reply; 8+ messages in thread
From: John Drescher @ 2013-10-12 13:36 UTC (permalink / raw)
  To: linux-kernel

I am trying to debug this problem since it appears this is causing
mythtv to truncate recordings on top of other very long delays.

 # uname -a
Linux jmd0.comcast.net 3.11.4-gentoo-jmd0 #1 SMP PREEMPT Mon Oct 7
21:04:44 EDT 2013 x86_64 Intel(R) Core(TM)2 Quad CPU Q9550 @ 2.83GHz
GenuineIntel GNU/Linux

Here is 1 example of a hung task:

[ 3000.576427] INFO: task TFWWrite:11329 blocked for more than 120 seconds.
[ 3000.576430] "echo 0 > /proc/sys/kernel/hung_task_
timeout_secs" disables this message.
[ 3000.576433] TFWWrite        D ffff8800a7ab5ac0     0 11329      1 0x00000000
[ 3000.576437]  ffff8800a7ab5a18 0000000000000082 0000000000000002
ffff8800a7ab5fd8
[ 3000.576442]  ffff8800a7ab5fd8 0000000000004000 ffff8801a6cfade0
ffff880099782de0
[ 3000.576445]  0000000000000000 00000000000000d3 00000000000001a6
0000000000000001
[ 3000.576449] Call Trace:
[ 3000.576458]  [<ffffffff81074bfe>] ? load_balance+0xfe/0x800
[ 3000.576462]  [<ffffffff8106e975>] ? sched_clock_local+0x25/0xa0
[ 3000.576466]  [<ffffffff810d89e0>] ? __lock_page+0x70/0x70
[ 3000.576471]  [<ffffffff81560664>] schedule+0x24/0x70
[ 3000.576474]  [<ffffffff8156073a>] io_schedule+0x8a/0xd0
[ 3000.576477]  [<ffffffff810d89e9>] sleep_on_page+0x9/0x10
[ 3000.576480]  [<ffffffff8155e133>] __wait_on_bit_lock+0x53/0xb0
[ 3000.576484]  [<ffffffff810d89d2>] __lock_page+0x62/0x70
[ 3000.576488]  [<ffffffff810603c0>] ? wake_atomic_t_function+0x30/0x30
[ 3000.576492]  [<ffffffff810d8b71>] find_lock_page+0x51/0x80
[ 3000.576495]  [<ffffffff810d948a>] find_or_create_page+0x3a/0xc0
[ 3000.576499]  [<ffffffff8128443c>] prepare_pages.isra.23+0x18c/0x340
[ 3000.576504]  [<ffffffff81255990>] ? block_rsv_add_bytes+0x50/0x70
[ 3000.576508]  [<ffffffff81284fca>] __btrfs_buffered_write+0x29a/0x4e0
[ 3000.576511]  [<ffffffff81285425>] btrfs_file_aio_write+0x215/0x580
[ 3000.576515]  [<ffffffff8111b30e>] ? kmem_cache_free+0xae/0x180
[ 3000.576519]  [<ffffffff8113a4a1>] ? final_putname+0x21/0x50
[ 3000.576523]  [<ffffffff8112eb1b>] do_sync_write+0x7b/0xb0
[ 3000.576527]  [<ffffffff8112f8f0>] vfs_write+0xc0/0x1f0
[ 3000.576530]  [<ffffffff8112fded>] SyS_write+0x4d/0xa0
[ 3000.576533]  [<ffffffff81567b92>] system_call_fastpath+0x16/0x1b
[ 3000.576556] INFO: task btrfs-transacti:6770 blocked for more than
120 seconds.
[ 3000.576558] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 3000.576559] btrfs-transacti D ffff8800a6d6f0c0     0  6770      2 0x00000000
[ 3000.576562]  ffff8801500f5dd8 0000000000000046 ffff8801500f5d18
ffff8801500f5fd8
[ 3000.576566]  ffff8801500f5fd8 0000000000004000 ffff88017f08dbc0
ffff88015eeb2de0
[ 3000.576569]  ffff8801a86c0000 ffff8801a86b3990 0000000000000000
0000000000000000
[ 3000.576573] Call Trace:
[ 3000.576577]  [<ffffffff8124cd05>] ? btrfs_free_path+0x25/0x30
[ 3000.576580]  [<ffffffff81561e26>] ? _raw_spin_lock+0x16/0x40
[ 3000.576583]  [<ffffffff81561be1>] ? _raw_spin_unlock+0x11/0x40
[ 3000.576587]  [<ffffffff8128b1ff>] ? btrfs_run_ordered_operations+0x20f/0x2c0
[ 3000.576590]  [<ffffffff81561e68>] ? _raw_spin_lock_irqsave+0x18/0x50
[ 3000.576593]  [<ffffffff81561c23>] ? _raw_spin_unlock_irqrestore+0x13/0x40
[ 3000.576596]  [<ffffffff81560664>] schedule+0x24/0x70
[ 3000.576600]  [<ffffffff81272d7d>] btrfs_commit_transaction+0x33d/0x960
[ 3000.576603]  [<ffffffff81060350>] ? abort_exclusive_wait+0xb0/0xb0
[ 3000.576607]  [<ffffffff8126ae3d>] transaction_kthread+0x19d/0x220
[ 3000.576610]  [<ffffffff8126aca0>] ? btrfs_alloc_root+0x30/0x30
[ 3000.576613]  [<ffffffff8105f7fb>] kthread+0xbb/0xc0
[ 3000.576617]  [<ffffffff81560000>] ? __schedule+0x4c0/0xa10
[ 3000.576620]  [<ffffffff8105f740>] ? kthread_freezable_should_stop+0x60/0x60
[ 3000.576623]  [<ffffffff81567aec>] ret_from_fork+0x7c/0xb0
[ 3000.576626]  [<ffffffff8105f740>] ? kthread_freezable_should_stop+0x60/0x60
[ 3000.576652] INFO: task mythpreviewgen:12052 blocked for more than
120 seconds.
[ 3000.576654] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 3000.576655] mythpreviewgen  D ffff88015f6e8670     0 12052  12051 0x00000004
[ 3000.576659]  ffff8801066adc08 0000000000000082 ffff8801066adb08
ffff8801066adfd8
[ 3000.576662]  ffff8801066adfd8 0000000000004000 ffff8801a6cf96f0
ffff88018080ade0
[ 3000.576665]  ffff8801a655d0c0 ffff8801a655d0c0 000000006d5f7675
0000000000000000
[ 3000.576669] Call Trace:
[ 3000.576676]  [<ffffffffa01f7d4a>] ? do_expire_wait+0x17a/0x190 [autofs4]
[ 3000.576680]  [<ffffffff81561e26>] ? _raw_spin_lock+0x16/0x40
[ 3000.576683]  [<ffffffff81561e26>] ? _raw_spin_lock+0x16/0x40
[ 3000.576686]  [<ffffffff81561be1>] ? _raw_spin_unlock+0x11/0x40
[ 3000.576689]  [<ffffffff81560664>] schedule+0x24/0x70
[ 3000.576692]  [<ffffffff81560943>] schedule_preempt_disabled+0x13/0x20
[ 3000.576695]  [<ffffffff8155f0ec>] __mutex_lock_slowpath+0x12c/0x210
[ 3000.576699]  [<ffffffff8155e23d>] mutex_lock+0x1d/0x40
[ 3000.576702]  [<ffffffff8113d6e8>] do_last+0x268/0xd20
[ 3000.576705]  [<ffffffff8113a773>] ? inode_permission+0x13/0x50
[ 3000.576708]  [<ffffffff8113accd>] ? link_path_walk+0x23d/0x8e0
[ 3000.576711]  [<ffffffff8113e25d>] path_openat+0xbd/0x6b0
[ 3000.576715]  [<ffffffff8113eb8e>] do_filp_open+0x3e/0xa0
[ 3000.576718]  [<ffffffff81561be1>] ? _raw_spin_unlock+0x11/0x40
[ 3000.576722]  [<ffffffff8114b31b>] ? __alloc_fd+0xcb/0x120
[ 3000.576725]  [<ffffffff8112e6ac>] do_sys_open+0x13c/0x230
[ 3000.576729]  [<ffffffff8112e7bd>] SyS_open+0x1d/0x20
[ 3000.576731]  [<ffffffff81567b92>] system_call_fastpath+0x16/0x1b
[ 3000.576734] INFO: task mythpreviewgen:12054 blocked for more than
120 seconds.
[ 3000.576736] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 3000.576737] mythpreviewgen  D ffff8801a86c06e0     0 12054  12053 0x00000004
[ 3000.576740]  ffff880121141b28 0000000000000086 ffff880121141aa8
ffff880121141fd8
[ 3000.576744]  ffff880121141fd8 0000000000004000 ffff8801a6cfade0
ffff88000a795bc0
[ 3000.576747]  ffff880121141b58 ffffffff8125c7c7 ffff880121141a68
ffffffff81561ca1
[ 3000.576751] Call Trace:
[ 3000.576755]  [<ffffffff8125c7c7>] ? reserve_metadata_bytes+0x177/0x880
[ 3000.576758]  [<ffffffff81561ca1>] ? _raw_read_unlock+0x11/0x40
[ 3000.576762]  [<ffffffff812a6f88>] ? btrfs_set_lock_blocking_rw+0xd8/0x110
[ 3000.576766]  [<ffffffff81251d6f>] ? btrfs_search_slot+0x3ef/0x900
[ 3000.576769]  [<ffffffff81561e68>] ? _raw_spin_lock_irqsave+0x18/0x50
[ 3000.576772]  [<ffffffff81561c23>] ? _raw_spin_unlock_irqrestore+0x13/0x40
[ 3000.576775]  [<ffffffff81560664>] schedule+0x24/0x70
[ 3000.576779]  [<ffffffff81272017>] wait_current_trans.isra.34+0xb7/0x120
[ 3000.576782]  [<ffffffff8127388c>] ? start_transaction+0x11c/0x4b0
[ 3000.576785]  [<ffffffff81060350>] ? abort_exclusive_wait+0xb0/0xb0
[ 3000.576789]  [<ffffffff81273a56>] start_transaction+0x2e6/0x4b0
[ 3000.576792]  [<ffffffff81273f66>] btrfs_start_transaction+0x16/0x20
[ 3000.576795]  [<ffffffff81280d82>] btrfs_create+0x42/0x210
[ 3000.576799]  [<ffffffff81275f27>] ? btrfs_permission+0x37/0x70
[ 3000.576802]  [<ffffffff8113a83e>] vfs_create+0x8e/0xf0
[ 3000.576805]  [<ffffffff8113dd66>] do_last+0x8e6/0xd20
[ 3000.576808]  [<ffffffff8113a773>] ? inode_permission+0x13/0x50
[ 3000.576812]  [<ffffffff8113e25d>] path_openat+0xbd/0x6b0
[ 3000.576815]  [<ffffffff8113eb8e>] do_filp_open+0x3e/0xa0
[ 3000.576818]  [<ffffffff81561be1>] ? _raw_spin_unlock+0x11/0x40
[ 3000.576821]  [<ffffffff8114b31b>] ? __alloc_fd+0xcb/0x120
[ 3000.576825]  [<ffffffff8112e6ac>] do_sys_open+0x13c/0x230
[ 3000.576828]  [<ffffffff8112e7bd>] SyS_open+0x1d/0x20
[ 3000.576831]  [<ffffffff81567b92>] system_call_fastpath+0x16/0x1b
[ 3120.576415] INFO: task TFWWrite:11329 blocked for more than 120 seconds.
[ 3120.576419] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 3120.576421] TFWWrite        D ffff8800a7ab5ac0     0 11329      1 0x00000000
[ 3120.576426]  ffff8800a7ab5a18 0000000000000082 0000000000000002
ffff8800a7ab5fd8
[ 3120.576431]  ffff8800a7ab5fd8 0000000000004000 ffff8801a6cfade0
ffff880099782de0
[ 3120.576434]  0000000000000000 00000000000000d3 00000000000001a6
0000000000000001
[ 3120.576438] Call Trace:
[ 3120.576447]  [<ffffffff81074bfe>] ? load_balance+0xfe/0x800
[ 3120.576451]  [<ffffffff8106e975>] ? sched_clock_local+0x25/0xa0
[ 3120.576455]  [<ffffffff810d89e0>] ? __lock_page+0x70/0x70
[ 3120.576460]  [<ffffffff81560664>] schedule+0x24/0x70
[ 3120.576463]  [<ffffffff8156073a>] io_schedule+0x8a/0xd0
[ 3120.576466]  [<ffffffff810d89e9>] sleep_on_page+0x9/0x10
[ 3120.576469]  [<ffffffff8155e133>] __wait_on_bit_lock+0x53/0xb0
[ 3120.576473]  [<ffffffff810d89d2>] __lock_page+0x62/0x70
[ 3120.576477]  [<ffffffff810603c0>] ? wake_atomic_t_function+0x30/0x30
[ 3120.576480]  [<ffffffff810d8b71>] find_lock_page+0x51/0x80
[ 3120.576483]  [<ffffffff810d948a>] find_or_create_page+0x3a/0xc0
[ 3120.576487]  [<ffffffff8128443c>] prepare_pages.isra.23+0x18c/0x340
[ 3120.576491]  [<ffffffff81255990>] ? block_rsv_add_bytes+0x50/0x70
[ 3120.576495]  [<ffffffff81284fca>] __btrfs_buffered_write+0x29a/0x4e0
[ 3120.576499]  [<ffffffff81285425>] btrfs_file_aio_write+0x215/0x580
[ 3120.576502]  [<ffffffff8111b30e>] ? kmem_cache_free+0xae/0x180
[ 3120.576506]  [<ffffffff8113a4a1>] ? final_putname+0x21/0x50
[ 3120.576510]  [<ffffffff8112eb1b>] do_sync_write+0x7b/0xb0
[ 3120.576514]  [<ffffffff8112f8f0>] vfs_write+0xc0/0x1f0
[ 3120.576517]  [<ffffffff8112fded>] SyS_write+0x4d/0xa0
[ 3120.576521]  [<ffffffff81567b92>] system_call_fastpath+0x16/0x1b
[ 3120.576543] INFO: task btrfs-transacti:6770 blocked for more than
120 seconds.
[ 3120.576545] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 3120.576546] btrfs-transacti D ffff8800a6d6f0c0     0  6770      2 0x00000000
[ 3120.576549]  ffff8801500f5dd8 0000000000000046 ffff8801500f5d18
ffff8801500f5fd8
[ 3120.576553]  ffff8801500f5fd8 0000000000004000 ffff88017f08dbc0
ffff88015eeb2de0
[ 3120.576556]  ffff8801a86c0000 ffff8801a86b3990 0000000000000000
0000000000000000
[ 3120.576560] Call Trace:
[ 3120.576563]  [<ffffffff8124cd05>] ? btrfs_free_path+0x25/0x30
[ 3120.576567]  [<ffffffff81561e26>] ? _raw_spin_lock+0x16/0x40
[ 3120.576570]  [<ffffffff81561be1>] ? _raw_spin_unlock+0x11/0x40
[ 3120.576573]  [<ffffffff8128b1ff>] ? btrfs_run_ordered_operations+0x20f/0x2c0
[ 3120.576577]  [<ffffffff81561e68>] ? _raw_spin_lock_irqsave+0x18/0x50
[ 3120.576580]  [<ffffffff81561c23>] ? _raw_spin_unlock_irqrestore+0x13/0x40
[ 3120.576583]  [<ffffffff81560664>] schedule+0x24/0x70
[ 3120.576587]  [<ffffffff81272d7d>] btrfs_commit_transaction+0x33d/0x960
[ 3120.576590]  [<ffffffff81060350>] ? abort_exclusive_wait+0xb0/0xb0
[ 3120.576594]  [<ffffffff8126ae3d>] transaction_kthread+0x19d/0x220
[ 3120.576597]  [<ffffffff8126aca0>] ? btrfs_alloc_root+0x30/0x30
[ 3120.576600]  [<ffffffff8105f7fb>] kthread+0xbb/0xc0
[ 3120.576604]  [<ffffffff81560000>] ? __schedule+0x4c0/0xa10
[ 3120.576607]  [<ffffffff8105f740>] ? kthread_freezable_should_stop+0x60/0x60
[ 3120.576610]  [<ffffffff81567aec>] ret_from_fork+0x7c/0xb0
[ 3120.576613]  [<ffffffff8105f740>] ? kthread_freezable_should_stop+0x60/0x60
[ 3120.576634] INFO: task kworker/u8:0:9957 blocked for more than 120 seconds.
[ 3120.576636] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 3120.576637] kworker/u8:0    D ffff8801a4716d20     0  9957      2 0x00000000
[ 3120.576644] Workqueue: writeback bdi_writeback_workfn (flush-btrfs-7)
[ 3120.576646]  ffff88010080b6f8 0000000000000046 0000000000000000
ffff88010080bfd8
[ 3120.576649]  ffff88010080bfd8 0000000000004000 ffff8801758e16f0
ffff88014e4f2de0
[ 3120.576653]  ffff88010080b668 ffffffff8111b477 ffffffff810dadf0
0001120000000010
[ 3120.576656] Call Trace:
[ 3120.576659]  [<ffffffff8111b477>] ? kmem_cache_alloc+0x57/0xf0
[ 3120.576663]  [<ffffffff810dadf0>] ? mempool_alloc_slab+0x10/0x20
[ 3120.576666]  [<ffffffff810dadf0>] ? mempool_alloc_slab+0x10/0x20
[ 3120.576668]  [<ffffffff810db0f5>] ? mempool_alloc+0x55/0x150
[ 3120.576672]  [<ffffffff81561e68>] ? _raw_spin_lock_irqsave+0x18/0x50
[ 3120.576675]  [<ffffffff81561c23>] ? _raw_spin_unlock_irqrestore+0x13/0x40
[ 3120.576678]  [<ffffffff81560664>] schedule+0x24/0x70
[ 3120.576682]  [<ffffffff81272017>] wait_current_trans.isra.34+0xb7/0x120
[ 3120.576685]  [<ffffffff81060350>] ? abort_exclusive_wait+0xb0/0xb0
[ 3120.576688]  [<ffffffff812739f8>] start_transaction+0x288/0x4b0
[ 3120.576692]  [<ffffffff81273ce2>] btrfs_join_transaction+0x12/0x20
[ 3120.576695]  [<ffffffff8127aa00>] cow_file_range+0x40/0xe0
[ 3120.576698]  [<ffffffff8127adfb>] run_delalloc_range+0x35b/0x390
[ 3120.576702]  [<ffffffff812907f9>] __extent_writepage+0x2b9/0x730
[ 3120.576706]  [<ffffffff8115c450>] ? end_buffer_async_read+0x1e0/0x1e0
[ 3120.576709]  [<ffffffff81162400>] ? I_BDEV+0x10/0x10
[ 3120.576713]  [<ffffffff813328c0>] ? merge+0x50/0xa0
[ 3120.576718]  [<ffffffff81290f02>]
extent_write_cache_pages.isra.40.constprop.57+0x292/0x3d0
[ 3120.576722]  [<ffffffff812912c8>] extent_writepages+0x48/0x60
[ 3120.576725]  [<ffffffff81276fd0>] ? btrfs_fiemap+0x60/0x60
[ 3120.576728]  [<ffffffff81275ee3>] btrfs_writepages+0x23/0x30
[ 3120.576732]  [<ffffffff810e2969>] do_writepages+0x19/0x40
[ 3120.576736]  [<ffffffff8115489e>] __writeback_single_inode+0x3e/0x140
[ 3120.576739]  [<ffffffff811559a6>] writeback_sb_inodes+0x276/0x3c0
[ 3120.576742]  [<ffffffff81155b87>] __writeback_inodes_wb+0x97/0xd0
[ 3120.576746]  [<ffffffff81155d8b>] wb_writeback+0x1cb/0x1e0
[ 3120.576749]  [<ffffffff811560ae>] bdi_writeback_workfn+0x15e/0x310
[ 3120.576754]  [<ffffffff810590d0>] process_one_work+0x140/0x390
[ 3120.576757]  [<ffffffff81059759>] worker_thread+0x119/0x370
[ 3120.576761]  [<ffffffff81059640>] ? rescuer_thread+0x2e0/0x2e0
[ 3120.576764]  [<ffffffff8105f7fb>] kthread+0xbb/0xc0
[ 3120.576767]  [<ffffffff81560000>] ? __schedule+0x4c0/0xa10
[ 3120.576771]  [<ffffffff8105f740>] ? kthread_freezable_should_stop+0x60/0x60
[ 3120.576774]  [<ffffffff81567aec>] ret_from_fork+0x7c/0xb0
[ 3120.576777]  [<ffffffff8105f740>] ? kthread_freezable_should_stop+0x60/0x60
[ 3120.576782] INFO: task mythpreviewgen:12052 blocked for more than
120 seconds.
[ 3120.576784] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 3120.576785] mythpreviewgen  D ffff88015f6e8670     0 12052  12051 0x00000004
[ 3120.576789]  ffff8801066adc08 0000000000000082 ffff8801066adb08
ffff8801066adfd8
[ 3120.576792]  ffff8801066adfd8 0000000000004000 ffff8801a6cf96f0
ffff88018080ade0
[ 3120.576796]  ffff8801a655d0c0 ffff8801a655d0c0 000000006d5f7675
0000000000000000
[ 3120.576799] Call Trace:
[ 3120.576807]  [<ffffffffa01f7d4a>] ? do_expire_wait+0x17a/0x190 [autofs4]
[ 3120.576810]  [<ffffffff81561e26>] ? _raw_spin_lock+0x16/0x40
[ 3120.576813]  [<ffffffff81561e26>] ? _raw_spin_lock+0x16/0x40
[ 3120.576816]  [<ffffffff81561be1>] ? _raw_spin_unlock+0x11/0x40
[ 3120.576819]  [<ffffffff81560664>] schedule+0x24/0x70
[ 3120.576823]  [<ffffffff81560943>] schedule_preempt_disabled+0x13/0x20
[ 3120.576826]  [<ffffffff8155f0ec>] __mutex_lock_slowpath+0x12c/0x210
[ 3120.576829]  [<ffffffff8155e23d>] mutex_lock+0x1d/0x40
[ 3120.576832]  [<ffffffff8113d6e8>] do_last+0x268/0xd20
[ 3120.576835]  [<ffffffff8113a773>] ? inode_permission+0x13/0x50
[ 3120.576838]  [<ffffffff8113accd>] ? link_path_walk+0x23d/0x8e0
[ 3120.576841]  [<ffffffff8113e25d>] path_openat+0xbd/0x6b0
[ 3120.576845]  [<ffffffff8113eb8e>] do_filp_open+0x3e/0xa0
[ 3120.576848]  [<ffffffff81561be1>] ? _raw_spin_unlock+0x11/0x40
[ 3120.576852]  [<ffffffff8114b31b>] ? __alloc_fd+0xcb/0x120
[ 3120.576855]  [<ffffffff8112e6ac>] do_sys_open+0x13c/0x230
[ 3120.576859]  [<ffffffff8112e7bd>] SyS_open+0x1d/0x20
[ 3120.576861]  [<ffffffff81567b92>] system_call_fastpath+0x16/0x1b
[ 3120.576864] INFO: task mythpreviewgen:12054 blocked for more than
120 seconds.
[ 3120.576866] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[ 3120.576867] mythpreviewgen  D ffff8801a86c06e0     0 12054  12053 0x00000004
[ 3120.576870]  ffff880121141b28 0000000000000086 ffff880121141aa8
ffff880121141fd8
[ 3120.576874]  ffff880121141fd8 0000000000004000 ffff8801a6cfade0
ffff88000a795bc0
[ 3120.576877]  ffff880121141b58 ffffffff8125c7c7 ffff880121141a68
ffffffff81561ca1
[ 3120.576881] Call Trace:
[ 3120.576885]  [<ffffffff8125c7c7>] ? reserve_metadata_bytes+0x177/0x880
[ 3120.576888]  [<ffffffff81561ca1>] ? _raw_read_unlock+0x11/0x40
[ 3120.576892]  [<ffffffff812a6f88>] ? btrfs_set_lock_blocking_rw+0xd8/0x110
[ 3120.576895]  [<ffffffff81251d6f>] ? btrfs_search_slot+0x3ef/0x900
[ 3120.576899]  [<ffffffff81561e68>] ? _raw_spin_lock_irqsave+0x18/0x50
[ 3120.576902]  [<ffffffff81561c23>] ? _raw_spin_unlock_irqrestore+0x13/0x40
[ 3120.576905]  [<ffffffff81560664>] schedule+0x24/0x70
[ 3120.576908]  [<ffffffff81272017>] wait_current_trans.isra.34+0xb7/0x120
[ 3120.576911]  [<ffffffff8127388c>] ? start_transaction+0x11c/0x4b0
[ 3120.576915]  [<ffffffff81060350>] ? abort_exclusive_wait+0xb0/0xb0
[ 3120.576918]  [<ffffffff81273a56>] start_transaction+0x2e6/0x4b0
[ 3120.576922]  [<ffffffff81273f66>] btrfs_start_transaction+0x16/0x20
[ 3120.576925]  [<ffffffff81280d82>] btrfs_create+0x42/0x210
[ 3120.576928]  [<ffffffff81275f27>] ? btrfs_permission+0x37/0x70
[ 3120.576931]  [<ffffffff8113a83e>] vfs_create+0x8e/0xf0
[ 3120.576934]  [<ffffffff8113dd66>] do_last+0x8e6/0xd20
[ 3120.576937]  [<ffffffff8113a773>] ? inode_permission+0x13/0x50
[ 3120.576941]  [<ffffffff8113e25d>] path_openat+0xbd/0x6b0
[ 3120.576944]  [<ffffffff8113eb8e>] do_filp_open+0x3e/0xa0
[ 3120.576947]  [<ffffffff81561be1>] ? _raw_spin_unlock+0x11/0x40
[ 3120.576951]  [<ffffffff8114b31b>] ? __alloc_fd+0xcb/0x120
[ 3120.576954]  [<ffffffff8112e6ac>] do_sys_open+0x13c/0x230
[ 3120.576957]  [<ffffffff8112e7bd>] SyS_open+0x1d/0x20
[ 3120.576960]  [<ffffffff81567b92>] system_call_fastpath+0x16/

-- 
John M. Drescher

^ permalink raw reply	[flat|nested] 8+ messages in thread
* btrfs hung tasks
@ 2011-07-28  6:23 Stephane Chazelas
  2011-07-28  8:46 ` Stephane Chazelas
                   ` (2 more replies)
  0 siblings, 3 replies; 8+ messages in thread
From: Stephane Chazelas @ 2011-07-28  6:23 UTC (permalink / raw)
  To: linux-btrfs

[-- Attachment #1: Type: text/plain, Size: 20330 bytes --]

Hiya, I got below those last night. That was 3 minutes after a
bunch of rsync and ntfsclone processes started.

It's the first time it happens. I upgraded from 3.0rc6 to 3.0
yesterday.

sysrq-t output attached.

[30961.476020] INFO: task kthreadd:2 blocked for more than 120 seconds.
[30961.482414] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[30961.490271] kthreadd        D ffff880149526e20     0     2      0 0x00000000
[30961.497489]  ffff880149526e20 0000000000000046 ffff88014fffb700 ffffea00007eb520
[30961.504977]  ffff880147045890 0000000000012800 ffff88014952ffd8 ffff88014952ffd8
[30961.512525]  0000000000012800 ffff880149526e20 0000000000012800 0000000000012800
[30961.520179] Call Trace:
[30961.522702]  [<ffffffff8100e342>] ? read_tsc+0x5/0x14
[30961.527850]  [<ffffffff81066feb>] ? timekeeping_get_ns+0xd/0x2a
[30961.533861]  [<ffffffff810b5c70>] ? lock_page+0x20/0x20
[30961.539134]  [<ffffffff813354f3>] ? io_schedule+0x5b/0x75
[30961.548853]  [<ffffffff810b5c79>] ? sleep_on_page+0x9/0x10
[30961.554424]  [<ffffffff81335b74>] ? __wait_on_bit+0x3e/0x71
[30961.560042]  [<ffffffff810b5e11>] ? wait_on_page_bit+0x6a/0x70
[30961.565912]  [<ffffffff810600ad>] ? autoremove_wake_function+0x2a/0x2a
[30961.572478]  [<ffffffff810ef92d>] ? migrate_pages+0x1b6/0x39b
[30961.578243]  [<ffffffff810e851b>] ? suitable_migration_target+0x35/0x35
[30961.584877]  [<ffffffff810e8ee2>] ? compact_zone+0x68e/0x6a1
[30961.590567]  [<ffffffff8110b5f1>] ? shrink_dcache_memory+0x132/0x15d
[30961.596934]  [<ffffffff810e9075>] ? compact_zone_order+0x9e/0xab
[30961.602954]  [<ffffffff810e9112>] ? try_to_compact_pages+0x90/0xe6
[30961.609147]  [<ffffffff810bc393>] ? __alloc_pages_direct_compact+0xac/0x163
[30961.616124]  [<ffffffff810bc8cf>] ? __alloc_pages_nodemask+0x485/0x75c
[30961.622665]  [<ffffffff81044a50>] ? copy_process+0x109/0x10eb
[30961.628462]  [<ffffffff8103b012>] ? perf_event_task_sched_out+0x48/0x54
[30961.635108]  [<ffffffff81045b60>] ? do_fork+0xff/0x263
[30961.640262]  [<ffffffff8100f1e0>] ? kernel_thread+0x7b/0x83
[30961.645846]  [<ffffffff8105fb91>] ? kthread_worker_fn+0x149/0x149
[30961.651955]  [<ffffffff8133cba0>] ? gs_change+0x13/0x13
[30961.657193]  [<ffffffff8105ff3e>] ? kthreadd+0xe7/0x125
[30961.662434]  [<ffffffff8103b0a2>] ? finish_task_switch+0x84/0xaf
[30961.668477]  [<ffffffff8133cba4>] ? kernel_thread_helper+0x4/0x10
[30961.674587]  [<ffffffff8105fe57>] ? tsk_fork_get_node+0x1a/0x1a
[30961.680518]  [<ffffffff8133cba0>] ? gs_change+0x13/0x13
[30961.685772] INFO: task btrfs-delayed-m:785 blocked for more than 120 seconds.
[30961.692919] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[30961.700793] btrfs-delayed-m D ffff88014628a300     0   785      2 0x00000000
[30961.707874]  ffff88014628a300 0000000000000046 ffff88014549cc28 000000000000eb3f
[30961.715347]  ffff880147044ab0 0000000000012800 ffff8801484c3fd8 ffff8801484c3fd8
[30961.722816]  0000000000012800 ffff88014628a300 0000000000012800 0000000000012800
[30961.730283] Call Trace:
[30961.732750]  [<ffffffff813367ec>] ? _raw_spin_lock_irqsave+0x9/0x25
[30961.739056]  [<ffffffffa02bb89c>] ? btrfs_tree_lock+0x9a/0xa7 [btrfs]
[30961.745524]  [<ffffffffa02bb754>] ? btrfs_spin_on_block+0x49/0x49 [btrfs]
[30961.752337]  [<ffffffffa027a16d>] ? btrfs_lock_root_node+0x1d/0x3f [btrfs]
[30961.759231]  [<ffffffffa027d7a1>] ? btrfs_search_slot+0xe6/0x4d6 [btrfs]
[30961.765948]  [<ffffffff81335ce4>] ? mutex_lock+0xd/0x2d
[30961.771190]  [<ffffffff8103840a>] ? should_resched+0x5/0x24
[30961.776809]  [<ffffffffa028c82a>] ? btrfs_lookup_inode+0x25/0x87 [btrfs]
[30961.783527]  [<ffffffff810383fc>] ? need_resched+0x1a/0x23
[30961.789062]  [<ffffffff8103840a>] ? should_resched+0x5/0x24
[30961.794654]  [<ffffffff8133565f>] ? _cond_resched+0x9/0x20
[30961.800155]  [<ffffffff81335ce4>] ? mutex_lock+0xd/0x2d
[30961.805412]  [<ffffffffa02cd6c3>] ? btrfs_update_delayed_inode+0x6b/0x126 [btrfs]
[30961.812967]  [<ffffffffa02ce2a0>] ? btrfs_async_run_delayed_node_done+0x9f/0x1cb [btrfs]
[30961.821126]  [<ffffffffa02b6f8a>] ? worker_loop+0x17e/0x498 [btrfs]
[30961.827420]  [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs]
[30961.834320]  [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs]
[30961.841209]  [<ffffffff8105fc0b>] ? kthread+0x7a/0x82
[30961.846276]  [<ffffffff8133cba4>] ? kernel_thread_helper+0x4/0x10
[30961.852381]  [<ffffffff8105fb91>] ? kthread_worker_fn+0x149/0x149
[30961.858487]  [<ffffffff8133cba0>] ? gs_change+0x13/0x13
[30961.863725] INFO: task btrfs-transacti:892 blocked for more than 120 seconds.
[30961.870870] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[30961.878727] btrfs-transacti D ffff880147e24ee0     0   892      2 0x00000000
[30961.885811]  ffff880147e24ee0 0000000000000046 ffffea000006f318 ffff880000000000
[30961.893280]  ffff8801495660c0 0000000000012800 ffff880144357fd8 ffff880144357fd8
[30961.900743]  0000000000012800 ffff880147e24ee0 0000000000012800 0000000000012800
[30961.908210] Call Trace:
[30961.910669]  [<ffffffff8100e342>] ? read_tsc+0x5/0x14
[30961.915737]  [<ffffffff810b5c70>] ? lock_page+0x20/0x20
[30961.920978]  [<ffffffff813354f3>] ? io_schedule+0x5b/0x75
[30961.926390]  [<ffffffff810b5c79>] ? sleep_on_page+0x9/0x10
[30961.931888]  [<ffffffff81335b74>] ? __wait_on_bit+0x3e/0x71
[30961.937473]  [<ffffffff810b5e11>] ? wait_on_page_bit+0x6a/0x70
[30961.943320]  [<ffffffff810600ad>] ? autoremove_wake_function+0x2a/0x2a
[30961.949871]  [<ffffffffa02ac5f5>] ? lock_page+0x11/0x20 [btrfs]
[30961.955817]  [<ffffffffa02af4e3>] ? extent_write_cache_pages.clone.10.clone.17+0xed/0x21f [btrfs]
[30961.964730]  [<ffffffff810be856>] ? pagevec_lookup_tag+0x18/0x1f
[30961.970757]  [<ffffffff810b6468>] ? filemap_fdatawait_range+0x12c/0x14a
[30961.977400]  [<ffffffffa02af864>] ? extent_writepages+0x44/0x5a [btrfs]
[30961.984042]  [<ffffffffa0296e09>] ? uncompress_inline.clone.32+0x117/0x117 [btrfs]
[30961.991639]  [<ffffffff810b6729>] ? __filemap_fdatawrite_range+0x4b/0x50
[30961.998365]  [<ffffffffa02abd38>] ? btrfs_wait_ordered_range+0x53/0x11e [btrfs]
[30962.005706]  [<ffffffff810383fc>] ? need_resched+0x1a/0x23
[30962.011202]  [<ffffffff8103840a>] ? should_resched+0x5/0x24
[30962.016799]  [<ffffffffa02abf30>] ? btrfs_run_ordered_operations+0x12d/0x1b6 [btrfs]
[30962.024584]  [<ffffffffa029354b>] ? btrfs_commit_transaction+0x22e/0x6fd [btrfs]
[30962.032011]  [<ffffffff810ece49>] ? kmem_cache_alloc+0x86/0xf0
[30962.037867]  [<ffffffffa0292c7b>] ? join_transaction.clone.23+0xbb/0x1fc [btrfs]
[30962.045293]  [<ffffffff81060083>] ? wake_up_bit+0x23/0x23
[30962.050705]  [<ffffffff810383fc>] ? need_resched+0x1a/0x23
[30962.056202]  [<ffffffff8103840a>] ? should_resched+0x5/0x24
[30962.061800]  [<ffffffffa028ddd7>] ? transaction_kthread+0x171/0x229 [btrfs]
[30962.068785]  [<ffffffffa028dc66>] ? btrfs_congested_fn+0x7b/0x7b [btrfs]
[30962.075508]  [<ffffffffa028dc66>] ? btrfs_congested_fn+0x7b/0x7b [btrfs]
[30962.082223]  [<ffffffff8105fc0b>] ? kthread+0x7a/0x82
[30962.087288]  [<ffffffff8133cba4>] ? kernel_thread_helper+0x4/0x10
[30962.093393]  [<ffffffff8105fb91>] ? kthread_worker_fn+0x149/0x149
[30962.099501]  [<ffffffff8133cba0>] ? gs_change+0x13/0x13
[30962.104755] INFO: task btrfs-delalloc-:2380 blocked for more than 120 seconds.
[30962.112007] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[30962.119860] btrfs-delalloc- D ffff880143f9a340     0  2380      2 0x00000000
[30962.126941]  ffff880143f9a340 0000000000000046 ffff88014fffbe00 ffffffff00000000
[30962.134410]  ffffffff8160b020 0000000000012800 ffff880111f49fd8 ffff880111f49fd8
[30962.141876]  0000000000012800 ffff880143f9a340 0000000000012800 0000000000012800
[30962.149344] Call Trace:
[30962.151803]  [<ffffffff81335939>] ? schedule_timeout+0x2d/0xd7
[30962.157651]  [<ffffffff8100e28d>] ? paravirt_read_tsc+0x5/0x8
[30962.163411]  [<ffffffff8100e74a>] ? native_sched_clock+0x28/0x30
[30962.169430]  [<ffffffff8100e757>] ? sched_clock+0x5/0x8
[30962.174669]  [<ffffffff81335713>] ? wait_for_common+0x9d/0x116
[30962.180518]  [<ffffffff8103f0a4>] ? try_to_wake_up+0x199/0x199
[30962.186365]  [<ffffffff8105fdb6>] ? kthread_create_on_node+0x8f/0x10a
[30962.192825]  [<ffffffffa02827be>] ? btrfs_put_block_group+0x73/0x73 [btrfs]
[30962.199802]  [<ffffffff810eccd8>] ? __kmalloc+0xde/0xf0
[30962.205040]  [<ffffffff810383fc>] ? need_resched+0x1a/0x23
[30962.210555]  [<ffffffffa028271a>] ? cache_block_group+0x1f3/0x224 [btrfs]
[30962.217367]  [<ffffffffa028620b>] ? find_free_extent.clone.64+0x41a/0x932 [btrfs]
[30962.224890]  [<ffffffffa02b0a14>] ? map_extent_buffer+0x6a/0xa1 [btrfs]
[30962.231525]  [<ffffffffa0287006>] ? btrfs_reserve_extent+0xb0/0x18e [btrfs]
[30962.238512]  [<ffffffffa028767a>] ? btrfs_alloc_free_block+0x219/0x33f [btrfs]
[30962.245769]  [<ffffffffa027d24c>] ? split_leaf+0x2c6/0x523 [btrfs]
[30962.251969]  [<ffffffffa027dad6>] ? btrfs_search_slot+0x41b/0x4d6 [btrfs]
[30962.258777]  [<ffffffffa027ea43>] ? btrfs_insert_empty_items+0x62/0xb3 [btrfs]
[30962.266041]  [<ffffffffa0298da3>] ? insert_inline_extent+0xa5/0x231 [btrfs]
[30962.273029]  [<ffffffffa0299056>] ? cow_file_range_inline+0x127/0x166 [btrfs]
[30962.280189]  [<ffffffffa029a431>] ? compress_file_range+0x326/0x55a [btrfs]
[30962.287176]  [<ffffffffa029a693>] ? async_cow_start+0x2e/0x43 [btrfs]
[30962.293644]  [<ffffffffa02b6f8a>] ? worker_loop+0x17e/0x498 [btrfs]
[30962.299934]  [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs]
[30962.306831]  [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs]
[30962.313721]  [<ffffffff8105fc0b>] ? kthread+0x7a/0x82
[30962.318787]  [<ffffffff8133cba4>] ? kernel_thread_helper+0x4/0x10
[30962.324893]  [<ffffffff8105fb91>] ? kthread_worker_fn+0x149/0x149
[30962.330999]  [<ffffffff8133cba0>] ? gs_change+0x13/0x13
[30962.336256] INFO: task btrfs-endio-wri:2442 blocked for more than 120 seconds.
[30962.343504] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[30962.351361] btrfs-endio-wri D ffff88013ee4d550     0  2442      2 0x00000000
[30962.358445]  ffff88013ee4d550 0000000000000046 ffff880028ef7b20 ffff880100e3ce20
[30962.365911]  ffff88003a95ea70 0000000000012800 ffff880028ef7fd8 ffff880028ef7fd8
[30962.373377]  0000000000012800 ffff88013ee4d550 0000000000012800 0000000000012800
[30962.380845] Call Trace:
[30962.383301]  [<ffffffff813367ec>] ? _raw_spin_lock_irqsave+0x9/0x25
[30962.389595]  [<ffffffffa02bb89c>] ? btrfs_tree_lock+0x9a/0xa7 [btrfs]
[30962.396063]  [<ffffffffa02bb754>] ? btrfs_spin_on_block+0x49/0x49 [btrfs]
[30962.402871]  [<ffffffffa0279edb>] ? btrfs_set_path_blocking+0x21/0x32 [btrfs]
[30962.410027]  [<ffffffffa027da81>] ? btrfs_search_slot+0x3c6/0x4d6 [btrfs]
[30962.416840]  [<ffffffffa028b5fb>] ? btrfs_lookup_file_extent+0x34/0x39 [btrfs]
[30962.424103]  [<ffffffffa02a03c1>] ? btrfs_drop_extents+0xe4/0x6eb [btrfs]
[30962.430904]  [<ffffffff810bd65d>] ? __set_page_dirty_nobuffers+0x16/0xd6
[30962.437619]  [<ffffffff810ed076>] ? kmem_cache_free+0x2d/0x69
[30962.443389]  [<ffffffffa0297beb>] ? insert_reserved_file_extent.clone.34+0x66/0x215 [btrfs]
[30962.451777]  [<ffffffffa0293e52>] ? start_transaction+0x1ec/0x227 [btrfs]
[30962.458585]  [<ffffffff810383fc>] ? need_resched+0x1a/0x23
[30962.464095]  [<ffffffffa0298a41>] ? btrfs_finish_ordered_io+0x1b6/0x298 [btrfs]
[30962.471433]  [<ffffffff810be064>] ? test_clear_page_writeback+0xb8/0xcc
[30962.478074]  [<ffffffffa02ad4dd>] ? end_bio_extent_writepage+0xa2/0x152 [btrfs]
[30962.489565]  [<ffffffffa02b6f8a>] ? worker_loop+0x17e/0x498 [btrfs]
[30962.495858]  [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs]
[30962.502755]  [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs]
[30962.509646]  [<ffffffff8105fc0b>] ? kthread+0x7a/0x82
[30962.514710]  [<ffffffff8133cba4>] ? kernel_thread_helper+0x4/0x10
[30962.520815]  [<ffffffff8105fb91>] ? kthread_worker_fn+0x149/0x149
[30962.526921]  [<ffffffff8133cba0>] ? gs_change+0x13/0x13
[30962.532177] INFO: task rsync:3139 blocked for more than 120 seconds.
[30962.538543] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[30962.546402] rsync           D ffff88013bb86040     0  3139   3040 0x00000000
[30962.553485]  ffff88013bb86040 0000000000000082 0000000000000000 ffffffff00000000
[30962.560951]  ffffffff8160b020 0000000000012800 ffff88010d093fd8 ffff88010d093fd8
[30962.568416]  0000000000012800 ffff88013bb86040 0000000000012800 0000000000012800
[30962.575876] Call Trace:
[30962.578357]  [<ffffffffa0292b91>] ? wait_current_trans.clone.22+0xa1/0xd0 [btrfs]
[30962.585870]  [<ffffffff81060083>] ? wake_up_bit+0x23/0x23
[30962.591292]  [<ffffffffa0293d3f>] ? start_transaction+0xd9/0x227 [btrfs]
[30962.598010]  [<ffffffff810ed076>] ? kmem_cache_free+0x2d/0x69
[30962.603782]  [<ffffffffa029dbb1>] ? btrfs_create+0x33/0x18d [btrfs]
[30962.610062]  [<ffffffff810eccd8>] ? __kmalloc+0xde/0xf0
[30962.615304]  [<ffffffff811038d1>] ? generic_permission+0xe/0x9b
[30962.621234]  [<ffffffff811053d2>] ? vfs_create+0x66/0x88
[30962.626558]  [<ffffffff81103bf2>] ? d_alloc_and_lookup+0x3a/0x60
[30962.632577]  [<ffffffff81105636>] ? do_last+0x242/0x584
[30962.637814]  [<ffffffff81106bea>] ? path_openat+0xc7/0x349
[30962.643313]  [<ffffffff810fb5f1>] ? do_sync_read+0xb1/0xea
[30962.648816]  [<ffffffff8103840a>] ? should_resched+0x5/0x24
[30962.654400]  [<ffffffff81106e98>] ? do_filp_open+0x2c/0x72
[30962.659898]  [<ffffffff8133565f>] ? _cond_resched+0x9/0x20
[30962.665402]  [<ffffffff811ac741>] ? __strncpy_from_user+0x19/0x4a
[30962.671509]  [<ffffffff81110208>] ? alloc_fd+0x69/0x110
[30962.676746]  [<ffffffff810fb138>] ? do_sys_open+0x5f/0xe6
[30962.682160]  [<ffffffff8133ba92>] ? system_call_fastpath+0x16/0x1b
[30962.688355] INFO: task btrfs-delayed-m:3321 blocked for more than 120 seconds.
[30962.695602] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[30962.703459] btrfs-delayed-m D ffff880147044ab0     0  3321      2 0x00000000
[30962.710549]  ffff880147044ab0 0000000000000046 ffff88014549cc28 000000000000eb3f
[30962.718016]  ffff880143e6e340 0000000000012800 ffff88006c569fd8 ffff88006c569fd8
[30962.725482]  0000000000012800 ffff880147044ab0 0000000000012800 0000000000012800
[30962.732948] Call Trace:
[30962.735405]  [<ffffffff813367ec>] ? _raw_spin_lock_irqsave+0x9/0x25
[30962.741698]  [<ffffffffa02bb89c>] ? btrfs_tree_lock+0x9a/0xa7 [btrfs]
[30962.748167]  [<ffffffffa02bb754>] ? btrfs_spin_on_block+0x49/0x49 [btrfs]
[30962.754973]  [<ffffffffa027a16d>] ? btrfs_lock_root_node+0x1d/0x3f [btrfs]
[30962.761869]  [<ffffffffa027d7a1>] ? btrfs_search_slot+0xe6/0x4d6 [btrfs]
[30962.768584]  [<ffffffff81335ce4>] ? mutex_lock+0xd/0x2d
[30962.773822]  [<ffffffff8103840a>] ? should_resched+0x5/0x24
[30962.779418]  [<ffffffffa028c82a>] ? btrfs_lookup_inode+0x25/0x87 [btrfs]
[30962.786133]  [<ffffffff810383fc>] ? need_resched+0x1a/0x23
[30962.791631]  [<ffffffff8103840a>] ? should_resched+0x5/0x24
[30962.797215]  [<ffffffff8133565f>] ? _cond_resched+0x9/0x20
[30962.802716]  [<ffffffff81335ce4>] ? mutex_lock+0xd/0x2d
[30962.807965]  [<ffffffffa02cd6c3>] ? btrfs_update_delayed_inode+0x6b/0x126 [btrfs]
[30962.815485]  [<ffffffffa02ce2a0>] ? btrfs_async_run_delayed_node_done+0x9f/0x1cb [btrfs]
[30962.823616]  [<ffffffffa02b6f8a>] ? worker_loop+0x17e/0x498 [btrfs]
[30962.829907]  [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs]
[30962.836807]  [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs]
[30962.843694]  [<ffffffff8105fc0b>] ? kthread+0x7a/0x82
[30962.848760]  [<ffffffff8133cba4>] ? kernel_thread_helper+0x4/0x10
[30962.854868]  [<ffffffff8105fb91>] ? kthread_worker_fn+0x149/0x149
[30962.860972]  [<ffffffff8133cba0>] ? gs_change+0x13/0x13
[30962.866210] INFO: task ntfsclone:3437 blocked for more than 120 seconds.
[30962.872923] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[30962.880777] ntfsclone       D ffff8800b26250a0     0  3437   3399 0x00000000
[30962.887856]  ffff8800b26250a0 0000000000000086 0000000000000296 ffffffff00000001
[30962.895323]  ffff8801428e6ee0 0000000000012800 ffff88003d6a3fd8 ffff88003d6a3fd8
[30962.902789]  0000000000012800 ffff8800b26250a0 0000000000012800 0000000000012800
[30962.910256] Call Trace:
[30962.912730]  [<ffffffffa0292b91>] ? wait_current_trans.clone.22+0xa1/0xd0 [btrfs]
[30962.920243]  [<ffffffff81060083>] ? wake_up_bit+0x23/0x23
[30962.925668]  [<ffffffffa029fb73>] ? __btrfs_buffered_write.clone.14+0x24b/0x29a [btrfs]
[30962.933711]  [<ffffffffa029ff5d>] ? btrfs_file_aio_write+0x39b/0x435 [btrfs]
[30962.940775]  [<ffffffff810fb507>] ? do_sync_write+0xb1/0xea
[30962.946363]  [<ffffffff811650d9>] ? security_file_permission+0x18/0x33
[30962.952907]  [<ffffffff810fbb1e>] ? vfs_write+0xa6/0xf9
[30962.958147]  [<ffffffff810fbd13>] ? sys_write+0x45/0x6b
[30962.963384]  [<ffffffff8133ba92>] ? system_call_fastpath+0x16/0x1b
[30962.969577] INFO: task btrfs-delayed-m:3438 blocked for more than 120 seconds.
[30962.976828] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[30962.984684] btrfs-delayed-m D ffff8801428e6ee0     0  3438      2 0x00000000
[30962.991762]  ffff8801428e6ee0 0000000000000046 ffff8800299ebcf0 ffff88010df02c70
[30962.999229]  ffff880101862ab0 0000000000012800 ffff8800299ebfd8 ffff8800299ebfd8
[30963.006695]  0000000000012800 ffff8801428e6ee0 0000000000012800 0000000000012800
[30963.014163] Call Trace:
[30963.016625]  [<ffffffff813367ec>] ? _raw_spin_lock_irqsave+0x9/0x25
[30963.022917]  [<ffffffffa02bb89c>] ? btrfs_tree_lock+0x9a/0xa7 [btrfs]
[30963.029384]  [<ffffffffa02bb754>] ? btrfs_spin_on_block+0x49/0x49 [btrfs]
[30963.036193]  [<ffffffffa0279edb>] ? btrfs_set_path_blocking+0x21/0x32 [btrfs]
[30963.043346]  [<ffffffffa027da81>] ? btrfs_search_slot+0x3c6/0x4d6 [btrfs]
[30963.050150]  [<ffffffff8103840a>] ? should_resched+0x5/0x24
[30963.055746]  [<ffffffffa028c82a>] ? btrfs_lookup_inode+0x25/0x87 [btrfs]
[30963.062460]  [<ffffffff810383fc>] ? need_resched+0x1a/0x23
[30963.067961]  [<ffffffff8103840a>] ? should_resched+0x5/0x24
[30963.073547]  [<ffffffff8133565f>] ? _cond_resched+0x9/0x20
[30963.079045]  [<ffffffff81335ce4>] ? mutex_lock+0xd/0x2d
[30963.084296]  [<ffffffffa02cd6c3>] ? btrfs_update_delayed_inode+0x6b/0x126 [btrfs]
[30963.091818]  [<ffffffffa02ce2a0>] ? btrfs_async_run_delayed_node_done+0x9f/0x1cb [btrfs]
[30963.099947]  [<ffffffffa02b6f8a>] ? worker_loop+0x17e/0x498 [btrfs]
[30963.106239]  [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs]
[30963.113138]  [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs]
[30963.120028]  [<ffffffff8105fc0b>] ? kthread+0x7a/0x82
[30963.125093]  [<ffffffff8133cba4>] ? kernel_thread_helper+0x4/0x10
[30963.131199]  [<ffffffff8105fb91>] ? kthread_worker_fn+0x149/0x149
[30963.137308]  [<ffffffff8133cba0>] ? gs_change+0x13/0x13
[30963.142544] INFO: task rsync:3439 blocked for more than 120 seconds.
[30963.148908] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[30963.156765] rsync           D ffff880114e02870     0  3439   3172 0x00000000
[30963.163843]  ffff880114e02870 0000000000000082 00000000000c0fff ffff880114e02ef8
[30963.171307]  ffff880146786040 0000000000012800 ffff8800d335bfd8 ffff8800d335bfd8
[30963.178775]  0000000000012800 ffff880114e02870 0000000000012800 0000000000012800
[30963.186240] Call Trace:
[30963.188704]  [<ffffffff813367ec>] ? _raw_spin_lock_irqsave+0x9/0x25
[30963.194994]  [<ffffffffa0292b91>] ? wait_current_trans.clone.22+0xa1/0xd0 [btrfs]
[30963.202511]  [<ffffffff81060083>] ? wake_up_bit+0x23/0x23
[30963.207936]  [<ffffffffa029fb73>] ? __btrfs_buffered_write.clone.14+0x24b/0x29a [btrfs]
[30963.215979]  [<ffffffffa029ff5d>] ? btrfs_file_aio_write+0x39b/0x435 [btrfs]
[30963.223043]  [<ffffffff811035df>] ? dget+0x12/0x1e
[30963.227846]  [<ffffffff8110ba59>] ? dput+0x29/0xea
[30963.232651]  [<ffffffff81111b05>] ? mntput_no_expire+0x21/0xd5
[30963.238499]  [<ffffffff810fb507>] ? do_sync_write+0xb1/0xea
[30963.244084]  [<ffffffff811650d9>] ? security_file_permission+0x18/0x33
[30963.250621]  [<ffffffff810fbb1e>] ? vfs_write+0xa6/0xf9
[30963.255860]  [<ffffffff810fbd13>] ? sys_write+0x45/0x6b
[30963.261097]  [<ffffffff8133ba92>] ? system_call_fastpath+0x16/0x1b

-- 
Stephane

[-- Attachment #2: sysrq-t.txt.xz --]
[-- Type: application/octet-stream, Size: 18152 bytes --]

^ permalink raw reply	[flat|nested] 8+ messages in thread
end of thread, other threads:[~2013-10-13 15:50 UTC | newest]

Thread overview: 8+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2013-10-12 13:36 btrfs hung tasks John Drescher
2013-10-13 15:50 ` Hugo Mills
  -- strict thread matches above, loose matches on Subject: below --
2011-07-28  6:23 Stephane Chazelas
2011-07-28  8:46 ` Stephane Chazelas
2011-07-28 13:31 ` Chris Samuel
2011-07-28 14:22 ` Josef Bacik
2011-07-29 12:29   ` Stephane Chazelas
2011-07-29 13:05     ` Josef Bacik

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.