Blcoked for more than 120 seconds

DISCUSSION Tobias 4 participants 15 messages Nov 28, 2011 – Dec 25, 2011 1 message not in the archive Btrfs file system

Share & tools

Tobias

author

2011-11-28 08:16 UTC #0 lore raw

Hi!

I have two Hardware-Raid Arrays. Each encrypted with dmcrypt and on each one btrfs on it (without snapshots). They are half-filled

I do rsyncs on these fs over night and i get these errors:

INFO: task flush-btrfs-2:1472 blocked for more than 120 seconds.

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
flush-btrfs-2 D ffff8802313fb1a0 0 1472 2 0x00000000
ffff880227c318d0 0000000000000046 ffff88006320b798 ffff88006320b768 ffff8802313fade0 ffff880227c31fd8 ffff880227c31fd8 ffff880227c31fd8 ffff880211da5bc0 ffff8802313fade0 ffff880227c318d0 ffffffff8108f1fd

Call Trace:
 [<ffffffff8108f1fd>] ? ktime_get_ts+0xad/0xe0
 [<ffffffff81109a30>] ? __lock_page+0x70/0x70
 [<ffffffff815ffb9f>] schedule+0x3f/0x60
 [<ffffffff815ffc4f>] io_schedule+0x8f/0xd0
 [<ffffffff81109a3e>] sleep_on_page+0xe/0x20
 [<ffffffff8160031a>] __wait_on_bit_lock+0x5a/0xc0
 [<ffffffff81109a27>] __lock_page+0x67/0x70
 [<ffffffff81085440>] ? autoremove_wake_function+0x40/0x40
 [<ffffffffa02430e1>] 
extent_write_cache_pages.isra.23.constprop.32+0x1e1/0x3b0 [btrfs]
 [<ffffffffa02434f5>] extent_writepages+0x45/0x60 [btrfs]
 [<ffffffffa0228710>] ? acls_after_inode_item+0xc0/0xc0 [btrfs]
 [<ffffffff81084fd4>] ? bit_waitqueue+0x14/0xc0
 [<ffffffffa0227958>] btrfs_writepages+0x28/0x30 [btrfs]
 [<ffffffff81114e81>] do_writepages+0x21/0x40
 [<ffffffff8118f0b0>] writeback_single_inode+0x180/0x430
 [<ffffffff8118f776>] writeback_sb_inodes+0x1b6/0x270
 [<ffffffff8118f8ce>] __writeback_inodes_wb+0x9e/0xd0
 [<ffffffff8118fb6b>] wb_writeback+0x26b/0x350
 [<ffffffff8118fce8>] wb_check_old_data_flush+0x98/0xa0
 [<ffffffff8119006c>] wb_do_writeback+0x15c/0x200
 [<ffffffff816000b5>] ? schedule_timeout+0x175/0x320
 [<ffffffff81071840>] ? usleep_range+0x50/0x50
 [<ffffffff81190193>] bdi_writeback_thread+0x83/0x2a0
 [<ffffffff81190110>] ? wb_do_writeback+0x200/0x200
 [<ffffffff8108496c>] kthread+0x8c/0xa0
 [<ffffffff8160bb74>] kernel_thread_helper+0x4/0x10
 [<ffffffff810848e0>] ? flush_kthread_worker+0xa0/0xa0
 [<ffffffff8160bb70>] ? gs_change+0x13/0x13
INFO: task rsync:1887 blocked for more than 120 seconds.

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
rsync D ffff880227d49ab0 0 1887 1884 0x00000000
ffff8801a2bd7b68 0000000000000086 ffff880200000000 ffff8801a2bd7b08 ffff880227d496f0 ffff8801a2bd7fd8 ffff8801a2bd7fd8 ffff8801a2bd7fd8 ffffffff81c0d020 ffff880227d496f0 0000000000000286 000000012fd942f0

Call Trace:
 [<ffffffff815ffb9f>] schedule+0x3f/0x60
 [<ffffffffa022422d>] wait_current_trans.isra.22+0x9d/0x100 [btrfs]
 [<ffffffff81085400>] ? add_wait_queue+0x60/0x60
 [<ffffffffa0225a50>] start_transaction+0x1f0/0x2b0 [btrfs]
 [<ffffffffa0225b65>] btrfs_join_transaction+0x15/0x20 [btrfs]
 [<ffffffffa0230788>] btrfs_dirty_inode+0x48/0x160 [btrfs]
 [<ffffffff8118dfb0>] __mark_inode_dirty+0x40/0x230
 [<ffffffff8117fed7>] file_update_time+0xe7/0x150
 [<ffffffffa02348a0>] btrfs_file_aio_write+0x1c0/0x510 [btrfs]
 [<ffffffff8112f11b>] ? handle_pte_fault+0x61b/0xac0
 [<ffffffff81166c62>] do_sync_write+0xd2/0x110
 [<ffffffff8128dacc>] ? security_file_permission+0x2c/0xb0
 [<ffffffff81167101>] ? rw_verify_area+0x61/0xf0
 [<ffffffff81167463>] vfs_write+0xb3/0x180
 [<ffffffff8116778a>] sys_write+0x4a/0x90
 [<ffffffff81609a02>] system_call_fastpath+0x16/0x1b
INFO: task btrfs-delalloc-:2148 blocked for more than 120 seconds.

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
btrfs-delalloc- D ffff880089b8c890 0 2148 2 0x00000000
ffff880039dbbb40 0000000000000046 0000000000000000 0000000000001000 ffff880089b8c4d0 ffff880039dbbfd8 ffff880039dbbfd8 ffff880039dbbfd8 ffff8802321444d0 ffff880089b8c4d0 0000000000000286 000000012fd942f0

Call Trace:
 [<ffffffff815ffb9f>] schedule+0x3f/0x60
 [<ffffffffa022422d>] wait_current_trans.isra.22+0x9d/0x100 [btrfs]
 [<ffffffff81085400>] ? add_wait_queue+0x60/0x60
 [<ffffffffa0225a50>] start_transaction+0x1f0/0x2b0 [btrfs]
 [<ffffffffa0225b65>] btrfs_join_transaction+0x15/0x20 [btrfs]
 [<ffffffffa022c07c>] cow_file_range+0x7c/0x3a0 [btrfs]
 [<ffffffffa022d0f2>] submit_compressed_extents+0x242/0x470 [btrfs]
 [<ffffffffa022d7cc>] ? compress_file_range+0x41c/0x610 [btrfs]
 [<ffffffffa022d3a4>] async_cow_submit+0x84/0x90 [btrfs]
 [<ffffffffa024c490>] run_ordered_completions+0x80/0xe0 [btrfs]
 [<ffffffffa024ce80>] worker_loop+0x180/0x560 [btrfs]
 [<ffffffffa024cd00>] ? btrfs_queue_worker+0x300/0x300 [btrfs]
 [<ffffffff8108496c>] kthread+0x8c/0xa0
 [<ffffffff8160bb74>] kernel_thread_helper+0x4/0x10
 [<ffffffff810848e0>] ? flush_kthread_worker+0xa0/0xa0
 [<ffffffff8160bb70>] ? gs_change+0x13/0x13
INFO: task rsync:2217 blocked for more than 120 seconds.

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
rsync D ffff880212624890 0 2217 2212 0x00000000
ffff8801acaabd98 0000000000000082 0000000000000000 0000000000000000 ffff8802126244d0 ffff8801acaabfd8 ffff8801acaabfd8 ffff8801acaabfd8 ffff88023212dbc0 ffff8802126244d0 0000000000000282 000000012fd942f0

Call Trace:
 [<ffffffff815ffb9f>] schedule+0x3f/0x60
 [<ffffffffa022422d>] wait_current_trans.isra.22+0x9d/0x100 [btrfs]
 [<ffffffff81085400>] ? add_wait_queue+0x60/0x60
 [<ffffffffa0225995>] start_transaction+0x135/0x2b0 [btrfs]
 [<ffffffff8117651a>] ? kern_path_create+0x8a/0x120
 [<ffffffffa0225de3>] btrfs_start_transaction+0x13/0x20 [btrfs]
 [<ffffffffa0231cb5>] btrfs_link+0xa5/0x1a0 [btrfs]
 [<ffffffff81173211>] vfs_link+0x101/0x190
 [<ffffffff81177648>] sys_linkat+0x168/0x180
 [<ffffffff8117767e>] sys_link+0x1e/0x20
 [<ffffffff81609a02>] system_call_fastpath+0x16/0x1b
INFO: task flush-btrfs-2:1472 blocked for more than 120 seconds.

Call Trace:
 [<ffffffff8108f1fd>] ? ktime_get_ts+0xad/0xe0
 [<ffffffff81109a30>] ? __lock_page+0x70/0x70
 [<ffffffff815ffb9f>] schedule+0x3f/0x60
 [<ffffffff815ffc4f>] io_schedule+0x8f/0xd0
 [<ffffffff81109a3e>] sleep_on_page+0xe/0x20
 [<ffffffff8160031a>] __wait_on_bit_lock+0x5a/0xc0
 [<ffffffff81109a27>] __lock_page+0x67/0x70
 [<ffffffff81085440>] ? autoremove_wake_function+0x40/0x40
 [<ffffffffa02430e1>] 
extent_write_cache_pages.isra.23.constprop.32+0x1e1/0x3b0 [btrfs]
 [<ffffffffa02434f5>] extent_writepages+0x45/0x60 [btrfs]
 [<ffffffffa0228710>] ? acls_after_inode_item+0xc0/0xc0 [btrfs]
 [<ffffffff81084fd4>] ? bit_waitqueue+0x14/0xc0
 [<ffffffffa0227958>] btrfs_writepages+0x28/0x30 [btrfs]
 [<ffffffff81114e81>] do_writepages+0x21/0x40
 [<ffffffff8118f0b0>] writeback_single_inode+0x180/0x430
 [<ffffffff8118f776>] writeback_sb_inodes+0x1b6/0x270
 [<ffffffff8118f8ce>] __writeback_inodes_wb+0x9e/0xd0
 [<ffffffff8118fb6b>] wb_writeback+0x26b/0x350
 [<ffffffff8118fce8>] wb_check_old_data_flush+0x98/0xa0
 [<ffffffff8119006c>] wb_do_writeback+0x15c/0x200
 [<ffffffff816000b5>] ? schedule_timeout+0x175/0x320
 [<ffffffff81071840>] ? usleep_range+0x50/0x50
 [<ffffffff81190193>] bdi_writeback_thread+0x83/0x2a0
 [<ffffffff81190110>] ? wb_do_writeback+0x200/0x200
 [<ffffffff8108496c>] kthread+0x8c/0xa0
 [<ffffffff8160bb74>] kernel_thread_helper+0x4/0x10
 [<ffffffff810848e0>] ? flush_kthread_worker+0xa0/0xa0
 [<ffffffff8160bb70>] ? gs_change+0x13/0x13
INFO: task rsync:1887 blocked for more than 120 seconds.

Call Trace:
 [<ffffffff815ffb9f>] schedule+0x3f/0x60
 [<ffffffffa022422d>] wait_current_trans.isra.22+0x9d/0x100 [btrfs]
 [<ffffffff81085400>] ? add_wait_queue+0x60/0x60
 [<ffffffffa0225a50>] start_transaction+0x1f0/0x2b0 [btrfs]
 [<ffffffffa0225b65>] btrfs_join_transaction+0x15/0x20 [btrfs]
 [<ffffffffa0230788>] btrfs_dirty_inode+0x48/0x160 [btrfs]
 [<ffffffff8118dfb0>] __mark_inode_dirty+0x40/0x230
 [<ffffffff8117fed7>] file_update_time+0xe7/0x150
 [<ffffffffa02348a0>] btrfs_file_aio_write+0x1c0/0x510 [btrfs]
 [<ffffffff8112f11b>] ? handle_pte_fault+0x61b/0xac0
 [<ffffffff81166c62>] do_sync_write+0xd2/0x110
 [<ffffffff8128dacc>] ? security_file_permission+0x2c/0xb0
 [<ffffffff81167101>] ? rw_verify_area+0x61/0xf0
 [<ffffffff81167463>] vfs_write+0xb3/0x180
 [<ffffffff8116778a>] sys_write+0x4a/0x90
 [<ffffffff81609a02>] system_call_fastpath+0x16/0x1b
INFO: task btrfs-delalloc-:2148 blocked for more than 120 seconds.

Call Trace:
 [<ffffffff815ffb9f>] schedule+0x3f/0x60
 [<ffffffffa022422d>] wait_current_trans.isra.22+0x9d/0x100 [btrfs]
 [<ffffffff81085400>] ? add_wait_queue+0x60/0x60
 [<ffffffffa0225a50>] start_transaction+0x1f0/0x2b0 [btrfs]
 [<ffffffffa0225b65>] btrfs_join_transaction+0x15/0x20 [btrfs]
 [<ffffffffa022c07c>] cow_file_range+0x7c/0x3a0 [btrfs]
 [<ffffffffa022d0f2>] submit_compressed_extents+0x242/0x470 [btrfs]
 [<ffffffffa022d7cc>] ? compress_file_range+0x41c/0x610 [btrfs]
 [<ffffffffa022d3a4>] async_cow_submit+0x84/0x90 [btrfs]
 [<ffffffffa024c490>] run_ordered_completions+0x80/0xe0 [btrfs]
 [<ffffffffa024ce80>] worker_loop+0x180/0x560 [btrfs]
 [<ffffffffa024cd00>] ? btrfs_queue_worker+0x300/0x300 [btrfs]
 [<ffffffff8108496c>] kthread+0x8c/0xa0
 [<ffffffff8160bb74>] kernel_thread_helper+0x4/0x10
 [<ffffffff810848e0>] ? flush_kthread_worker+0xa0/0xa0
 [<ffffffff8160bb70>] ? gs_change+0x13/0x13
INFO: task rsync:2217 blocked for more than 120 seconds.

Call Trace:
 [<ffffffff815ffb9f>] schedule+0x3f/0x60
 [<ffffffffa022422d>] wait_current_trans.isra.22+0x9d/0x100 [btrfs]
 [<ffffffff81085400>] ? add_wait_queue+0x60/0x60
 [<ffffffffa0225995>] start_transaction+0x135/0x2b0 [btrfs]
 [<ffffffff8117651a>] ? kern_path_create+0x8a/0x120
 [<ffffffffa0225de3>] btrfs_start_transaction+0x13/0x20 [btrfs]
 [<ffffffffa0231cb5>] btrfs_link+0xa5/0x1a0 [btrfs]
 [<ffffffff81173211>] vfs_link+0x101/0x190
 [<ffffffff81177648>] sys_linkat+0x168/0x180
 [<ffffffff8117767e>] sys_link+0x1e/0x20
 [<ffffffff81609a02>] system_call_fastpath+0x16/0x1b
INFO: task flush-btrfs-2:1472 blocked for more than 120 seconds.

Call Trace:
 [<ffffffff8108f1fd>] ? ktime_get_ts+0xad/0xe0
 [<ffffffff81109a30>] ? __lock_page+0x70/0x70
 [<ffffffff815ffb9f>] schedule+0x3f/0x60
 [<ffffffff815ffc4f>] io_schedule+0x8f/0xd0
 [<ffffffff81109a3e>] sleep_on_page+0xe/0x20
 [<ffffffff8160031a>] __wait_on_bit_lock+0x5a/0xc0
 [<ffffffff81109a27>] __lock_page+0x67/0x70
 [<ffffffff81085440>] ? autoremove_wake_function+0x40/0x40
 [<ffffffffa02430e1>] 
extent_write_cache_pages.isra.23.constprop.32+0x1e1/0x3b0 [btrfs]
 [<ffffffffa02434f5>] extent_writepages+0x45/0x60 [btrfs]
 [<ffffffffa0228710>] ? acls_after_inode_item+0xc0/0xc0 [btrfs]
 [<ffffffff81084fd4>] ? bit_waitqueue+0x14/0xc0
 [<ffffffffa0227958>] btrfs_writepages+0x28/0x30 [btrfs]
 [<ffffffff81114e81>] do_writepages+0x21/0x40
 [<ffffffff8118f0b0>] writeback_single_inode+0x180/0x430
 [<ffffffff8118f776>] writeback_sb_inodes+0x1b6/0x270
 [<ffffffff8118f8ce>] __writeback_inodes_wb+0x9e/0xd0
 [<ffffffff8118fb6b>] wb_writeback+0x26b/0x350
 [<ffffffff8118fce8>] wb_check_old_data_flush+0x98/0xa0
 [<ffffffff8119006c>] wb_do_writeback+0x15c/0x200
 [<ffffffff816000b5>] ? schedule_timeout+0x175/0x320
 [<ffffffff81071840>] ? usleep_range+0x50/0x50
 [<ffffffff81190193>] bdi_writeback_thread+0x83/0x2a0
 [<ffffffff81190110>] ? wb_do_writeback+0x200/0x200
 [<ffffffff8108496c>] kthread+0x8c/0xa0
 [<ffffffff8160bb74>] kernel_thread_helper+0x4/0x10
 [<ffffffff810848e0>] ? flush_kthread_worker+0xa0/0xa0
 [<ffffffff8160bb70>] ? gs_change+0x13/0x13
INFO: task rsync:1887 blocked for more than 120 seconds.

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
rsync D ffff880227d49ab0 0 1887 1884 0x00000004
ffff8801a2bd7b68 0000000000000086 ffff880200000000 ffff8801a2bd7b08 ffff880227d496f0 ffff8801a2bd7fd8 ffff8801a2bd7fd8 ffff8801a2bd7fd8 ffffffff81c0d020 ffff880227d496f0 0000000000000286 000000012fd942f0

Call Trace:
 [<ffffffff815ffb9f>] schedule+0x3f/0x60
 [<ffffffffa022422d>] wait_current_trans.isra.22+0x9d/0x100 [btrfs]
 [<ffffffff81085400>] ? add_wait_queue+0x60/0x60
 [<ffffffffa0225a50>] start_transaction+0x1f0/0x2b0 [btrfs]
 [<ffffffffa0225b65>] btrfs_join_transaction+0x15/0x20 [btrfs]
 [<ffffffffa0230788>] btrfs_dirty_inode+0x48/0x160 [btrfs]
 [<ffffffff8118dfb0>] __mark_inode_dirty+0x40/0x230
 [<ffffffff8117fed7>] file_update_time+0xe7/0x150
 [<ffffffffa02348a0>] btrfs_file_aio_write+0x1c0/0x510 [btrfs]
 [<ffffffff8112f11b>] ? handle_pte_fault+0x61b/0xac0
 [<ffffffff81166c62>] do_sync_write+0xd2/0x110
 [<ffffffff8128dacc>] ? security_file_permission+0x2c/0xb0
 [<ffffffff81167101>] ? rw_verify_area+0x61/0xf0
 [<ffffffff81167463>] vfs_write+0xb3/0x180
 [<ffffffff8116778a>] sys_write+0x4a/0x90
 [<ffffffff81609a02>] system_call_fastpath+0x16/0x1b

I seems that the problem got worse the more data i put on the fs...

Sometime the system is still usable; sometimes i cant access the fs anymore (no even sync or umount) and have to hard-reset.

The problem occurs on the stock ubuntu kernel 2.6.38-8, 3.0.0-12, 3.0.0-13 and on my self-compiled 3.1.2.

Can anyone help?

Tobias

Chris Samuel

2011-11-28 09:29 UTC #1 lore raw

Hi Tobias,

Quoted 2 lines · Tobias

The problem occurs on the stock ubuntu kernel 2.6.38-8, 3.0.0-12, 3.0.0-13 and on my self-compiled 3.1.2.

There's a lot of work gone into btrfs in 3.2,
it would be interesting to know (speaking as
just another user) whether it still occurs
with 3.2-rc3.

cheers,
Chris

Signature · 1 line

Chris Samuel - http://www.csamuel.org/

Tobias

author

2011-11-30 09:44 UTC #2 lore raw

Re: Blocked for more than 120 seconds

Am 28.11.2011 10:29, schrieb Chris Samuel:

Quoted 11 lines

Hi Tobias,
Quoted 2 lines · Tobias
The problem occurs on the stock ubuntu kernel 2.6.38-8, 3.0.0-12, 3.0.0-13 and on my self-compiled 3.1.2.
There's a lot of work gone into btrfs in 3.2,
it would be interesting to know (speaking as
just another user) whether it still occurs
with 3.2-rc3.

I tried 3.2-rc3 tonight but the messages are still there:

[46203.412044] INFO: task rsync:1653 blocked for more than 120 seconds.
[46203.412056] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[46203.412066] rsync           D ffff8801d7d51aa0     0  1653   1647 0x00000000
[46203.412073]  ffff8800042b1d98 0000000000000086 0000000000000000 0000000000000000
[46203.412079]  ffff8801d7d516e0 ffff8800042b1fd8 ffff8800042b1fd8 ffff8800042b1fd8
[46203.412084]  ffff88023212db80 ffff8801d7d516e0 0000000000000282 0000000122103228
[46203.412090] Call Trace:
[46203.412101]  [<ffffffff8161259f>] schedule+0x3f/0x60
[46203.412126]  [<ffffffffa01fd1bd>] wait_current_trans.isra.22+0x9d/0x100 [btrfs]
[46203.412132]  [<ffffffff81085a40>] ? add_wait_queue+0x60/0x60
[46203.412148]  [<ffffffffa01fe7f5>] start_transaction+0x135/0x2b0 [btrfs]
[46203.412154]  [<ffffffff8117bd5a>] ? kern_path_create+0x8a/0x120
[46203.412171]  [<ffffffffa01fec43>] btrfs_start_transaction+0x13/0x20 [btrfs]
[46203.412188]  [<ffffffffa020a885>] btrfs_link+0xa5/0x1a0 [btrfs]
[46203.412193]  [<ffffffff81178a91>] vfs_link+0x101/0x190
[46203.412197]  [<ffffffff8117ce88>] sys_linkat+0x168/0x180
[46203.412200]  [<ffffffff8117cebe>] sys_link+0x1e/0x20
[46203.412205]  [<ffffffff8161c442>] system_call_fastpath+0x16/0x1b
[46563.412042] INFO: task btrfs-delalloc-:31614 blocked for more than 120 seconds.
[46563.412054] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[46563.412064] btrfs-delalloc- D ffff8801f8529aa0     0 31614      2 0x00000000
[46563.412071]  ffff8801330bdc50 0000000000000046 0000000000000000 0000000000000004
[46563.412077]  ffff8801f85296e0 ffff8801330bdfd8 ffff8801330bdfd8 ffff8801330bdfd8
[46563.412082]  ffff88023212db80 ffff8801f85296e0 0000000000000282 0000000122103228
[46563.412088] Call Trace:
[46563.412098]  [<ffffffff8161259f>] schedule+0x3f/0x60
[46563.412124]  [<ffffffffa01fd1bd>] wait_current_trans.isra.22+0x9d/0x100 [btrfs]
[46563.412130]  [<ffffffff81085a40>] ? add_wait_queue+0x60/0x60
[46563.412146]  [<ffffffffa01fe8b0>] start_transaction+0x1f0/0x2b0 [btrfs]
[46563.412163]  [<ffffffffa01fe9c5>] btrfs_join_transaction+0x15/0x20 [btrfs]
[46563.412179]  [<ffffffffa0206423>] compress_file_range+0x2d3/0x610 [btrfs]
[46563.412197]  [<ffffffffa0206795>] async_cow_start+0x35/0x50 [btrfs]
[46563.412213]  [<ffffffffa02269ba>] worker_loop+0x16a/0x560 [btrfs]
[46563.412231]  [<ffffffffa0226850>] ? btrfs_queue_worker+0x300/0x300 [btrfs]
[46563.412236]  [<ffffffff81084fac>] kthread+0x8c/0xa0
[46563.412241]  [<ffffffff8161e5b4>] kernel_thread_helper+0x4/0x10
[46563.412246]  [<ffffffff81084f20>] ? flush_kthread_worker+0xa0/0xa0
[46563.412250]  [<ffffffff8161e5b0>] ? gs_change+0x13/0x13
[46563.412255] INFO: task flush-btrfs-1:323 blocked for more than 120 seconds.
[46563.412263] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[46563.412273] flush-btrfs-1   D ffff8802129bb180     0   323      2 0x00000000
[46563.412278]  ffff8800209c58e0 0000000000000046 ffff880000000000 ffff8800218a2710
[46563.412284]  ffff8802129badc0 ffff8800209c5fd8 ffff8800209c5fd8 ffff8800209c5fd8
[46563.412290]  ffff8802321444a0 ffff8802129badc0 ffff8800209c58e0 000000018108f20d
[46563.412295] Call Trace:
[46563.412300]  [<ffffffff8110dc90>] ? __lock_page+0x70/0x70
[46563.412305]  [<ffffffff8161259f>] schedule+0x3f/0x60
[46563.412309]  [<ffffffff8161264f>] io_schedule+0x8f/0xd0
[46563.412313]  [<ffffffff8110dc9e>] sleep_on_page+0xe/0x20
[46563.412317]  [<ffffffff81612d1a>] __wait_on_bit_lock+0x5a/0xc0
[46563.412321]  [<ffffffff8110dc87>] __lock_page+0x67/0x70
[46563.412325]  [<ffffffff81085a80>] ? autoremove_wake_function+0x40/0x40
[46563.412342]  [<ffffffffa021c945>] extent_write_cache_pages.isra.21.constprop.31+0x215/0x3f0 [btrfs]
[46563.412361]  [<ffffffffa021cd65>] extent_writepages+0x45/0x60 [btrfs]
[46563.412378]  [<ffffffffa0201350>] ? acls_after_inode_item+0xc0/0xc0 [btrfs]
[46563.412382]  [<ffffffff81085614>] ? bit_waitqueue+0x14/0xc0
[46563.412398]  [<ffffffffa0200448>] btrfs_writepages+0x28/0x30 [btrfs]
[46563.412403]  [<ffffffff811195f1>] do_writepages+0x21/0x40
[46563.412409]  [<ffffffff81194c70>] writeback_single_inode+0x180/0x430
[46563.412413]  [<ffffffff81195336>] writeback_sb_inodes+0x1b6/0x270
[46563.412418]  [<ffffffff8119548e>] __writeback_inodes_wb+0x9e/0xd0
[46563.412422]  [<ffffffff8119573b>] wb_writeback+0x27b/0x330
[46563.412427]  [<ffffffff81187352>] ? get_nr_dirty_inodes+0x52/0x80
[46563.412432]  [<ffffffff8119588f>] wb_check_old_data_flush+0x9f/0xb0
[46563.412436]  [<ffffffff81196731>] wb_do_writeback+0x151/0x1d0
[46563.412441]  [<ffffffff81611fd4>] ? __schedule+0x3d4/0x8d0
[46563.412446]  [<ffffffff81071ae0>] ? usleep_range+0x50/0x50
[46563.412450]  [<ffffffff81196833>] bdi_writeback_thread+0x83/0x2a0
[46563.412455]  [<ffffffff811967b0>] ? wb_do_writeback+0x1d0/0x1d0
[46563.412459]  [<ffffffff81084fac>] kthread+0x8c/0xa0
[46563.412463]  [<ffffffff8161e5b4>] kernel_thread_helper+0x4/0x10
[46563.412468]  [<ffffffff81084f20>] ? flush_kthread_worker+0xa0/0xa0
[46563.412472]  [<ffffffff8161e5b0>] ? gs_change+0x13/0x13
[46563.412475] INFO: task rsync:1653 blocked for more than 120 seconds.
[46563.412483] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[46563.412493] rsync           D ffff8801d7d51aa0     0  1653   1647 0x00000000
[46563.412498]  ffff8800042b1d98 0000000000000086 0000000000000000 0000000000000000
[46563.412504]  ffff8801d7d516e0 ffff8800042b1fd8 ffff8800042b1fd8 ffff8800042b1fd8
[46563.412510]  ffff88023212db80 ffff8801d7d516e0 0000000000000282 0000000122103228
[46563.412515] Call Trace:
[46563.412520]  [<ffffffff8161259f>] schedule+0x3f/0x60
[46563.412535]  [<ffffffffa01fd1bd>] wait_current_trans.isra.22+0x9d/0x100 [btrfs]
[46563.412540]  [<ffffffff81085a40>] ? add_wait_queue+0x60/0x60
[46563.412555]  [<ffffffffa01fe7f5>] start_transaction+0x135/0x2b0 [btrfs]
[46563.412561]  [<ffffffff8117bd5a>] ? kern_path_create+0x8a/0x120
[46563.412577]  [<ffffffffa01fec43>] btrfs_start_transaction+0x13/0x20 [btrfs]
[46563.412594]  [<ffffffffa020a885>] btrfs_link+0xa5/0x1a0 [btrfs]
[46563.412599]  [<ffffffff81178a91>] vfs_link+0x101/0x190
[46563.412603]  [<ffffffff8117ce88>] sys_linkat+0x168/0x180
[46563.412606]  [<ffffffff8117cebe>] sys_link+0x1e/0x20
[46563.412610]  [<ffffffff8161c442>] system_call_fastpath+0x16/0x1b
[46563.412616] INFO: task rsync:2240 blocked for more than 120 seconds.
[46563.412624] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[46563.412633] rsync           D ffff8802286d1aa0     0  2240   1760 0x00000000
[46563.412638]  ffff88001b9b7d98 0000000000000086 0000000000000000 0000000000000000
[46563.412644]  ffff8802286d16e0 ffff88001b9b7fd8 ffff88001b9b7fd8 ffff88001b9b7fd8
[46563.412650]  ffff88023212db80 ffff8802286d16e0 0000000000000282 0000000122103228
[46563.412655] Call Trace:
[46563.412660]  [<ffffffff8161259f>] schedule+0x3f/0x60
[46563.412676]  [<ffffffffa01fd1bd>] wait_current_trans.isra.22+0x9d/0x100 [btrfs]
[46563.412680]  [<ffffffff81085a40>] ? add_wait_queue+0x60/0x60
[46563.412696]  [<ffffffffa01fe7f5>] start_transaction+0x135/0x2b0 [btrfs]
[46563.412700]  [<ffffffff8117bd5a>] ? kern_path_create+0x8a/0x120
[46563.412716]  [<ffffffffa01fec43>] btrfs_start_transaction+0x13/0x20 [btrfs]
[46563.412733]  [<ffffffffa020a885>] btrfs_link+0xa5/0x1a0 [btrfs]
[46563.412738]  [<ffffffff81178a91>] vfs_link+0x101/0x190
[46563.412742]  [<ffffffff8117ce88>] sys_linkat+0x168/0x180
[46563.412746]  [<ffffffff8117cebe>] sys_link+0x1e/0x20
[46563.412749]  [<ffffffff8161c442>] system_call_fastpath+0x16/0x1b
[46563.412754] INFO: task rsync:2257 blocked for more than 120 seconds.
[46563.412762] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[46563.412771] rsync           D ffff880232145f40     0  2257   2254 0x00000000
[46563.412777]  ffff88009c5c3b58 0000000000000086 ffff880000000000 ffffffff8108572e
[46563.412782]  ffff880232145b80 ffff88009c5c3fd8 ffff88009c5c3fd8 ffff88009c5c3fd8
[46563.412788]  ffff880232128000 ffff880232145b80 0000000000000286 0000000122103228
[46563.412793] Call Trace:
[46563.412797]  [<ffffffff8108572e>] ? wake_up_bit+0x2e/0x40
[46563.412802]  [<ffffffff8161259f>] schedule+0x3f/0x60
[46563.412818]  [<ffffffffa01fd1bd>] wait_current_trans.isra.22+0x9d/0x100 [btrfs]
[46563.412822]  [<ffffffff81085a40>] ? add_wait_queue+0x60/0x60
[46563.412838]  [<ffffffffa01fe8b0>] start_transaction+0x1f0/0x2b0 [btrfs]
[46563.412854]  [<ffffffffa01fe9c5>] btrfs_join_transaction+0x15/0x20 [btrfs]
[46563.412871]  [<ffffffffa0209368>] btrfs_dirty_inode+0x48/0x160 [btrfs]
[46563.412876]  [<ffffffff81194440>] __mark_inode_dirty+0x40/0x230
[46563.412880]  [<ffffffff81185814>] file_update_time+0xe4/0x150
[46563.412897]  [<ffffffffa020d500>] btrfs_file_aio_write+0x1c0/0x510 [btrfs]
[46563.412903]  [<ffffffff8125e857>] ? jbd2_journal_stop+0x1b7/0x2a0
[46563.412908]  [<ffffffff81177d03>] ? putname+0x33/0x50
[46563.412913]  [<ffffffff8116c422>] do_sync_write+0xd2/0x110
[46563.412918]  [<ffffffff812d5e98>] ? apparmor_file_permission+0x18/0x20
[46563.412924]  [<ffffffff8129c57c>] ? security_file_permission+0x2c/0xb0
[46563.412928]  [<ffffffff8116c9b1>] ? rw_verify_area+0x61/0xf0
[46563.412932]  [<ffffffff8116cd13>] vfs_write+0xb3/0x180
[46563.412936]  [<ffffffff8116d03a>] sys_write+0x4a/0x90
[46563.412940]  [<ffffffff8161c442>] system_call_fastpath+0x16/0x1b

Can anyone help?

Tobias

Chris Mason

2011-11-30 14:10 UTC #3 lore raw

Re: Blocked for more than 120 seconds

Quoted 5 lines · Tobias

Am 28.11.2011 10:29, schrieb Chris Samuel:
Quoted 4 lines
Hi Tobias,
On Mon, 28 Nov 2011, 19:16:25 EST, Tobias<[email protected]> wrote:

Quoted 8 lines

Quoted 7 lines
Quoted 2 lines
The problem occurs on the stock ubuntu kernel 2.6.38-8, 3.0.0-12, 3.0.0-13 and on my self-compiled 3.1.2.
There's a lot of work gone into btrfs in 3.2,
it would be interesting to know (speaking as
just another user) whether it still occurs
with 3.2-rc3.
I tried 3.2-rc3 tonight but the messages are still there:

We see a bunch of procs stuck waiting to start a transaction, but we don't see why they are waiting. Could you please capture a sysrq-t during this? That will show us all the waiters everywhere. We're really looking for the one proc stuck in btrfs_commit_transaction, he's the key to the stalls.

-chris

A message that is not in the archive (sent off-list or not yet received): [email protected]

Chris Mason

2011-12-01 18:41 UTC #5 lore raw

Re: Blocked for more than 120 seconds

Quoted 10 lines · Tobias

Hi Chris
Am 30.11.2011 15:10, schrieb Chris Mason:
Quoted 6 lines
We see a bunch of procs stuck waiting to start a transaction, but we don't see why they are waiting. Could you please capture a sysrq-t during this? That will show us all the waiters everywhere. We're really looking for the one proc stuck in btrfs_commit_transaction, he's the key to the stalls.

Quoted 2 lines

This is my first time working with sysrq... i hope i did it right... Here is the logoutput (quite much)

So, the transaction close is in btrfs_evict_inode, which sounds like a deadlock recently fixed by this commit:

http://git.kernel.org/?p=linux/kernel/git/mason/linux-btrfs.git;a=commit;h=aa38a711a893accf5b5192f3d705a120deaa81e0

If you pull the for-linus branch from today, hopefully the problem will be gone.

-chris

Tobias

author

2011-12-02 13:46 UTC #6 lore raw

Re: Blocked for more than 120 seconds

Hi Chris!

Am 01.12.2011 19:41, schrieb Chris Mason:

Quoted 9 lines

So, the transaction close is in btrfs_evict_inode, which sounds like a deadlock recently fixed by this commit:
http://git.kernel.org/?p=linux/kernel/git/mason/linux-btrfs.git;a=commit;h=aa38a711a893accf5b5192f3d705a120deaa81e0
If you pull the for-linus branch from today, hopefully the problem will be gone.

This looks very good. With this Kernel i still have some hangs, but only in rsync, only under high load and they don't lock up the system - so i guess it's ok now.

Thank You very much for Your help!

When will this patches go into the main Kernel?

Tobias

Chris Mason

2011-12-02 14:01 UTC #7 lore raw

Re: Blocked for more than 120 seconds

Quoted 13 lines · Tobias

Hi Chris!
Am 01.12.2011 19:41, schrieb Chris Mason:
Quoted 9 lines
So, the transaction close is in btrfs_evict_inode, which sounds like a deadlock recently fixed by this commit:
http://git.kernel.org/?p=linux/kernel/git/mason/linux-btrfs.git;a=commit;h=aa38a711a893accf5b5192f3d705a120deaa81e0
If you pull the for-linus branch from today, hopefully the problem will be gone.

Quoted 5 lines

This looks very good. With this Kernel i still have some hangs, but only in rsync, only under high load and they don't lock up the system - so i guess it's ok now.
Thank You very much for Your help!

Glad to hear this is working. All the credit to Miao, who found the deadlock.

Quoted 2 lines

When will this patches go into the main Kernel?

Linus pulled them in yesterday.

-chris

Konstantinos Skarlatos

2011-12-04 12:11 UTC #8 lore raw

Re: Blocked for more than 120 seconds

even more kernel messages from btrfs crashing when rsyncing large=20 amounts of data on 3.2rc4

Dec  3 15:12:14 mail kernel: [15481.100564] loop0           D=20
000000010044b6c5     0  1729      2 0x00000000
Dec  3 15:12:14 mail kernel: [15481.101550]  ffff8801f9b31b30=20
0000000000000046 0000000000000000 0000000000000000
Dec  3 15:12:14 mail kernel: [15481.102548]  ffff880200950e40=20
ffff8801f9b31fd8 ffff8801f9b31fd8 ffff8801f9b31fd8
Dec  3 15:12:14 mail kernel: [15481.103539]  ffff880202cb7200=20
ffff880200950e40 0000000000000002 ffff8801f9b31b78
Dec  3 15:12:14 mail kernel: [15481.104533] Call Trace:
Dec  3 15:12:14 mail kernel: [15481.105531]  [<ffffffff81101a55>] ?=20
find_get_pages_tag+0x125/0x150
Dec  3 15:12:14 mail kernel: [15481.106541]  [<ffffffff8110e205>] ?=20
pagevec_lookup_tag+0x25/0x40
Dec  3 15:12:14 mail kernel: [15481.107552]  [<ffffffff8101d639>] ?=20
read_tsc+0x9/0x20
Dec  3 15:12:14 mail kernel: [15481.108576]  [<ffffffff8108f14d>] ?=20
ktime_get_ts+0xad/0xe0
Dec  3 15:12:14 mail kernel: [15481.109592]  [<ffffffff81101d60>] ?=20
__lock_page+0x70/0x70
Dec  3 15:12:14 mail kernel: [15481.110607]  [<ffffffff814140bf>]=20
schedule+0x3f/0x60
Dec  3 15:12:14 mail kernel: [15481.111619]  [<ffffffff8141416f>]=20
io_schedule+0x8f/0xd0
Dec  3 15:12:14 mail kernel: [15481.112641]  [<ffffffff81101d6e>]=20
sleep_on_page+0xe/0x20
Dec  3 15:12:14 mail kernel: [15481.113639]  [<ffffffff8141491f>]=20
__wait_on_bit+0x5f/0x90
Dec  3 15:12:14 mail kernel: [15481.114629]  [<ffffffff81101f58>]=20
wait_on_page_bit+0x78/0x80
Dec  3 15:12:14 mail kernel: [15481.115628]  [<ffffffff81085790>] ?=20
autoremove_wake_function+0x40/0x40
Dec  3 15:12:14 mail kernel: [15481.116614]  [<ffffffff811020cc>]=20
filemap_fdatawait_range+0x10c/0x1a0
Dec  3 15:12:14 mail kernel: [15481.117613]  [<ffffffff811030c8>]=20
filemap_write_and_wait_range+0x68/0x80
Dec  3 15:12:14 mail kernel: [15481.118630]  [<ffffffffa03a7234>]=20
xfs_file_fsync+0x54/0x340 [xfs]
Dec  3 15:12:14 mail kernel: [15481.119629]  [<ffffffff8119148b>]=20
vfs_fsync+0x2b/0x40
Dec  3 15:12:14 mail kernel: [15481.120627]  [<ffffffffa04dacf2>]=20
do_bio_filebacked+0x1b2/0x320 [loop]
Dec  3 15:12:14 mail kernel: [15481.121645]  [<ffffffffa050efac>] ?=20
end_workqueue_bio+0x9c/0xa0 [btrfs]
Dec  3 15:12:14 mail kernel: [15481.122668]  [<ffffffffa04daf1b>]=20
loop_thread+0xbb/0x260 [loop]
Dec  3 15:12:14 mail kernel: [15481.123674]  [<ffffffff81085750>] ?=20
abort_exclusive_wait+0xb0/0xb0
Dec  3 15:12:14 mail kernel: [15481.124676]  [<ffffffffa04dae60>] ?=20
do_bio_filebacked+0x320/0x320 [loop]
Dec  3 15:12:14 mail kernel: [15481.125698]  [<ffffffff81084e0c>]=20
kthread+0x8c/0xa0
Dec  3 15:12:14 mail kernel: [15481.126710]  [<ffffffff81419a34>]=20
kernel_thread_helper+0x4/0x10
Dec  3 15:12:14 mail kernel: [15481.127721]  [<ffffffff81084d80>] ?=20
kthread_worker_fn+0x190/0x190
Dec  3 15:12:14 mail kernel: [15481.128742]  [<ffffffff81419a30>] ?=20
gs_change+0x13/0x13
Dec  3 15:12:14 mail kernel: [15481.131702] btrfs-transacti D=20
ffff8801f9ab7200     0  1756      2 0x00000000
Dec  3 15:12:14 mail kernel: [15481.132723]  ffff8801e7533bc0=20
0000000000000046 ffff88020fc93400 0000000000000002
Dec  3 15:12:14 mail kernel: [15481.133744]  ffff8801f9ab7200=20
ffff8801e7533fd8 ffff8801e7533fd8 ffff8801e7533fd8
Dec  3 15:12:14 mail kernel: [15481.134771]  ffff880200950e40=20
ffff8801f9ab7200 ffff8801e7533b10 0000000081051ae2
Dec  3 15:12:14 mail kernel: [15481.135813] Call Trace:
Dec  3 15:12:14 mail kernel: [15481.136828]  [<ffffffff8105ad36>] ?=20
ttwu_do_activate.constprop.172+0x66/0x70
Dec  3 15:12:14 mail kernel: [15481.137863]  [<ffffffff8105bd6e>] ?=20
try_to_wake_up+0x1de/0x290
Dec  3 15:12:14 mail kernel: [15481.138914]  [<ffffffff814140bf>]=20
schedule+0x3f/0x60
Dec  3 15:12:14 mail kernel: [15481.139956]  [<ffffffff814147d5>]=20
schedule_timeout+0x305/0x390
Dec  3 15:12:14 mail kernel: [15481.141007]  [<ffffffff8104d003>] ?=20
__wake_up+0x53/0x70
Dec  3 15:12:14 mail kernel: [15481.142074]  [<ffffffff81413348>]=20
wait_for_common+0xc8/0x160
Dec  3 15:12:14 mail kernel: [15481.143124]  [<ffffffff8105be20>] ?=20
try_to_wake_up+0x290/0x290
Dec  3 15:12:14 mail kernel: [15481.144170]  [<ffffffff814133fd>]=20
wait_for_completion+0x1d/0x20
Dec  3 15:12:14 mail kernel: [15481.145229]  [<ffffffffa050f0bb>]=20
write_dev_flush+0x4b/0x140 [btrfs]
Dec  3 15:12:14 mail kernel: [15481.146275]  [<ffffffffa0511086>]=20
write_all_supers+0x6f6/0x800 [btrfs]
Dec  3 15:12:14 mail kernel: [15481.147317]  [<ffffffffa05111a3>]=20
write_ctree_super+0x13/0x20 [btrfs]
Dec  3 15:12:14 mail kernel: [15481.148354]  [<ffffffffa05164dd>]=20
btrfs_commit_transaction+0x63d/0x880 [btrfs]
Dec  3 15:12:14 mail kernel: [15481.149397]  [<ffffffff81085750>] ?=20
abort_exclusive_wait+0xb0/0xb0
Dec  3 15:12:14 mail kernel: [15481.150416]  [<ffffffffa0516b74>] ?=20
start_transaction+0x94/0x2b0 [btrfs]
Dec  3 15:12:14 mail kernel: [15481.151444]  [<ffffffffa050ed4d>]=20
transaction_kthread+0x26d/0x290 [btrfs]
Dec  3 15:12:14 mail kernel: [15481.152492]  [<ffffffffa050eae0>] ?=20
btrfs_congested_fn+0xd0/0xd0 [btrfs]
Dec  3 15:12:14 mail kernel: [15481.153519]  [<ffffffff81084e0c>]=20
kthread+0x8c/0xa0
Dec  3 15:12:14 mail kernel: [15481.154542]  [<ffffffff81419a34>]=20
kernel_thread_helper+0x4/0x10
Dec  3 15:12:14 mail kernel: [15481.155553]  [<ffffffff81084d80>] ?=20
kthread_worker_fn+0x190/0x190
Dec  3 15:12:14 mail kernel: [15481.156522]  [<ffffffff81419a30>] ?=20
gs_change+0x13/0x13
Dec  3 15:12:14 mail kernel: [15481.159519] smbd            D=20
000000010044b8d7     0  2058    823 0x00000004
Dec  3 15:12:14 mail kernel: [15481.160544]  ffff88005cf37a08=20
0000000000000082 ffff88005cf37938 ffffffff81371188
Dec  3 15:12:14 mail kernel: [15481.161588]  ffff8802012e63c0=20
ffff88005cf37fd8 ffff88005cf37fd8 ffff88005cf37fd8
Dec  3 15:12:14 mail kernel: [15481.162658]  ffff880202d21c80=20
ffff8802012e63c0 ffff8802012769c0 0000000000000246
Dec  3 15:12:14 mail kernel: [15481.163708] Call Trace:
Dec  3 15:12:14 mail kernel: [15481.164736]  [<ffffffff81371188>] ?=20
sch_direct_xmit+0x68/0x1d0
Dec  3 15:12:14 mail kernel: [15481.165781]  [<ffffffff81355a00>] ?=20
dev_queue_xmit+0x200/0x680
Dec  3 15:12:14 mail kernel: [15481.166805]  [<ffffffff81389200>] ?=20
ip_forward_options+0x1c0/0x1c0
Dec  3 15:12:14 mail kernel: [15481.167822]  [<ffffffff8138adbe>] ?=20
ip_finish_output+0x18e/0x310
Dec  3 15:12:14 mail kernel: [15481.168850]  [<ffffffff8101d639>] ?=20
read_tsc+0x9/0x20
Dec  3 15:12:14 mail kernel: [15481.169853]  [<ffffffff8108f14d>] ?=20
ktime_get_ts+0xad/0xe0
Dec  3 15:12:14 mail kernel: [15481.170849]  [<ffffffff81101d60>] ?=20
__lock_page+0x70/0x70
Dec  3 15:12:14 mail kernel: [15481.171858]  [<ffffffff814140bf>]=20
schedule+0x3f/0x60
Dec  3 15:12:14 mail kernel: [15481.172851]  [<ffffffff8141416f>]=20
io_schedule+0x8f/0xd0
Dec  3 15:12:14 mail kernel: [15481.173844]  [<ffffffff81101d6e>]=20
sleep_on_page+0xe/0x20
Dec  3 15:12:14 mail kernel: [15481.174836]  [<ffffffff8141491f>]=20
__wait_on_bit+0x5f/0x90
Dec  3 15:12:14 mail kernel: [15481.175845]  [<ffffffff81101f58>]=20
wait_on_page_bit+0x78/0x80
Dec  3 15:12:14 mail kernel: [15481.176842]  [<ffffffff81085790>] ?=20
autoremove_wake_function+0x40/0x40
Dec  3 15:12:14 mail kernel: [15481.177845]  [<ffffffff81102845>]=20
grab_cache_page_write_begin+0x95/0xe0
Dec  3 15:12:14 mail kernel: [15481.178872]  [<ffffffffa03a1150>] ?=20
xfs_get_blocks_direct+0x20/0x20 [xfs]
Dec  3 15:12:14 mail kernel: [15481.179888]  [<ffffffff811967b8>]=20
block_write_begin+0x38/0xa0
Dec  3 15:12:14 mail kernel: [15481.180904]  [<ffffffffa03a1213>]=20
xfs_vm_write_begin+0x43/0x70 [xfs]
Dec  3 15:12:14 mail kernel: [15481.181928]  [<ffffffff8110233c>]=20
generic_file_buffered_write+0x10c/0x270
Dec  3 15:12:14 mail kernel: [15481.182955]  [<ffffffffa03aad66>] ?=20
xfs_iunlock+0x116/0x180 [xfs]
Dec  3 15:12:14 mail kernel: [15481.183979]  [<ffffffffa03a7fef>]=20
xfs_file_buffered_aio_write+0x10f/0x200 [xfs]
Dec  3 15:12:14 mail kernel: [15481.185011]  [<ffffffffa03a8252>]=20
xfs_file_aio_write+0x172/0x2a0 [xfs]
Dec  3 15:12:14 mail kernel: [15481.186052]  [<ffffffff81162d62>]=20
do_sync_write+0xd2/0x110
Dec  3 15:12:14 mail kernel: [15481.187073]  [<ffffffff811f0fcc>] ?=20
security_file_permission+0x2c/0xb0
Dec  3 15:12:14 mail kernel: [15481.188096]  [<ffffffff81163311>] ?=20
rw_verify_area+0x61/0xf0
Dec  3 15:12:14 mail kernel: [15481.189127]  [<ffffffff8116366f>]=20
vfs_write+0xaf/0x180
Dec  3 15:12:14 mail kernel: [15481.190141]  [<ffffffff81163b12>]=20
sys_pwrite64+0x82/0xb0
Dec  3 15:12:14 mail kernel: [15481.191149]  [<ffffffff814178c2>]=20
system_call_fastpath+0x16/0x1b
Dec  3 15:12:14 mail kernel: [15481.194224] kworker/2:3     D=20
0000000000000000     0  3713      2 0x00000000
Dec  3 15:12:14 mail kernel: [15481.195273]  ffff880005d49cc0=20
0000000000000046 0000000246417c40 0000000800000000
Dec  3 15:12:14 mail kernel: [15481.196304]  ffff8802013eaac0=20
ffff880005d49fd8 ffff880005d49fd8 ffff880005d49fd8
Dec  3 15:12:14 mail kernel: [15481.197329]  ffff8802013eeae0=20
ffff8802013eaac0 ffff880005d49c20 ffffffffa03a3fcb
Dec  3 15:12:14 mail kernel: [15481.198345] Call Trace:
Dec  3 15:12:14 mail kernel: [15481.199365]  [<ffffffffa03a3fcb>] ?=20
xfs_buf_iorequest+0x6b/0x100 [xfs]
Dec  3 15:12:14 mail kernel: [15481.200393]  [<ffffffffa03fa603>] ?=20
xlog_bdstrat+0x23/0x60 [xfs]
Dec  3 15:12:14 mail kernel: [15481.201408]  [<ffffffffa03fb287>] ?=20
xlog_sync+0x1d7/0x3c0 [xfs]
Dec  3 15:12:14 mail kernel: [15481.202419]  [<ffffffff814140bf>]=20
schedule+0x3f/0x60
Dec  3 15:12:14 mail kernel: [15481.203418]  [<ffffffffa03fe62b>]=20
_xfs_log_force_lsn+0x29b/0x2d0 [xfs]
Dec  3 15:12:14 mail kernel: [15481.204420]  [<ffffffff8105be20>] ?=20
try_to_wake_up+0x290/0x290
Dec  3 15:12:14 mail kernel: [15481.205438]  [<ffffffffa03fa23b>]=20
xfs_trans_commit+0x29b/0x2b0 [xfs]
Dec  3 15:12:14 mail kernel: [15481.206450]  [<ffffffffa03b4c60>] ?=20
xfs_sync_inode_attr+0xf0/0xf0 [xfs]
Dec  3 15:12:14 mail kernel: [15481.207466]  [<ffffffffa03aa162>]=20
xfs_fs_log_dummy+0x62/0x90 [xfs]
Dec  3 15:12:14 mail kernel: [15481.208486]  [<ffffffff8111ff90>] ?=20
refresh_cpu_vm_stats+0x1a0/0x1a0
Dec  3 15:12:14 mail kernel: [15481.209504]  [<ffffffffa03b4ce4>]=20
xfs_sync_worker+0x84/0x90 [xfs]
Dec  3 15:12:14 mail kernel: [15481.210518]  [<ffffffff8107f446>]=20
process_one_work+0x116/0x4d0
Dec  3 15:12:14 mail kernel: [15481.211531]  [<ffffffff8107fdde>]=20
worker_thread+0x15e/0x350
Dec  3 15:12:14 mail kernel: [15481.212559]  [<ffffffff8107fc80>] ?=20
manage_workers.isra.29+0x230/0x230
Dec  3 15:12:14 mail kernel: [15481.213573]  [<ffffffff81084e0c>]=20
kthread+0x8c/0xa0
Dec  3 15:12:14 mail kernel: [15481.214577]  [<ffffffff81419a34>]=20
kernel_thread_helper+0x4/0x10
Dec  3 15:12:14 mail kernel: [15481.215596]  [<ffffffff81084d80>] ?=20
kthread_worker_fn+0x190/0x190
Dec  3 15:12:14 mail kernel: [15481.216600]  [<ffffffff81419a30>] ?=20
gs_change+0x13/0x13
Dec  3 15:14:14 mail kernel: [15601.217226] xfsbufd/md127   D=20
00000001004562e8     0   527      2 0x00000000
Dec  3 15:14:14 mail kernel: [15601.218264]  ffff8801f912fab0=20
0000000000000046 0000000100000000 0000000300000001
Dec  3 15:14:14 mail kernel: [15601.219326]  ffff8802009dc740=20
ffff8801f912ffd8 ffff8801f912ffd8 ffff8801f912ffd8
Dec  3 15:14:14 mail kernel: [15601.220375]  ffffffff8180d020=20
ffff8802009dc740 ffff8801f912fa10 ffffffff8104d003
Dec  3 15:14:14 mail kernel: [15601.221411] Call Trace:
Dec  3 15:14:14 mail kernel: [15601.222441]  [<ffffffff8104d003>] ?=20
__wake_up+0x53/0x70
Dec  3 15:14:14 mail kernel: [15601.223461]  [<ffffffff8114d48b>] ?=20
kfree+0x3b/0x170
Dec  3 15:14:14 mail kernel: [15601.224479]  [<ffffffffa01c732b>] ?=20
plugger_unplug+0x3b/0x50 [md_mod]
Dec  3 15:14:14 mail kernel: [15601.225507]  [<ffffffff8121b457>] ?=20
blk_flush_plug_list+0xa7/0x250
Dec  3 15:14:14 mail kernel: [15601.226516]  [<ffffffff814140bf>]=20
schedule+0x3f/0x60
Dec  3 15:14:14 mail kernel: [15601.227516]  [<ffffffffa0378209>]=20
get_active_stripe+0x2e9/0x600 [raid456]
Dec  3 15:14:14 mail kernel: [15601.228540]  [<ffffffff8105be20>] ?=20
try_to_wake_up+0x290/0x290
Dec  3 15:14:14 mail kernel: [15601.229552]  [<ffffffffa037be22>]=20
make_request+0x192/0x430 [raid456]
Dec  3 15:14:14 mail kernel: [15601.230569]  [<ffffffff81085750>] ?=20
abort_exclusive_wait+0xb0/0xb0
Dec  3 15:14:14 mail kernel: [15601.231588]  [<ffffffffa01c964a>]=20
md_make_request+0xfa/0x240 [md_mod]
Dec  3 15:14:14 mail kernel: [15601.232628]  [<ffffffff811047a5>] ?=20
mempool_alloc_slab+0x15/0x20
Dec  3 15:14:14 mail kernel: [15601.233654]  [<ffffffff81219917>]=20
generic_make_request+0xc7/0x100
Dec  3 15:14:14 mail kernel: [15601.234682]  [<ffffffff812199d7>]=20
submit_bio+0x87/0x110
Dec  3 15:14:14 mail kernel: [15601.235731]  [<ffffffffa03a3e6c>]=20
_xfs_buf_ioapply+0x15c/0x1c0 [xfs]
Dec  3 15:14:14 mail kernel: [15601.236772]  [<ffffffffa03a4d75>] ?=20
xfs_bdstrat_cb+0x65/0x120 [xfs]
Dec  3 15:14:14 mail kernel: [15601.237815]  [<ffffffffa03a3fb9>]=20
xfs_buf_iorequest+0x59/0x100 [xfs]
Dec  3 15:14:14 mail kernel: [15601.238874]  [<ffffffffa03a4d75>]=20
xfs_bdstrat_cb+0x65/0x120 [xfs]
Dec  3 15:14:14 mail kernel: [15601.239916]  [<ffffffffa03a4f3e>]=20
xfsbufd+0x10e/0x170 [xfs]
Dec  3 15:14:14 mail kernel: [15601.240949]  [<ffffffff8105be32>] ?=20
default_wake_function+0x12/0x20
Dec  3 15:14:14 mail kernel: [15601.241995]  [<ffffffffa03a4e30>] ?=20
xfs_bdstrat_cb+0x120/0x120 [xfs]
Dec  3 15:14:14 mail kernel: [15601.243026]  [<ffffffff81084e0c>]=20
kthread+0x8c/0xa0
Dec  3 15:14:14 mail kernel: [15601.244051]  [<ffffffff81419a34>]=20
kernel_thread_helper+0x4/0x10
Dec  3 15:14:14 mail kernel: [15601.245076]  [<ffffffff81084d80>] ?=20
kthread_worker_fn+0x190/0x190
Dec  3 15:14:14 mail kernel: [15601.246114]  [<ffffffff81419a30>] ?=20
gs_change+0x13/0x13
Dec  3 15:14:14 mail kernel: [15601.249209] md127_resync    D=20
00000001004562fa     0   529      2 0x00000000
Dec  3 15:14:14 mail kernel: [15601.250259]  ffff8801f9073b80=20
0000000000000046 0000000100000000 ffffffff81233ce7
Dec  3 15:14:14 mail kernel: [15601.251316]  ffff8802013e8720=20
ffff8801f9073fd8 ffff8801f9073fd8 ffff8801f9073fd8
Dec  3 15:14:14 mail kernel: [15601.252392]  ffff880202cb4e60=20
ffff8802013e8720 ffff880200b70138 ffff880004bff300
Dec  3 15:14:14 mail kernel: [15601.253459] Call Trace:
Dec  3 15:14:14 mail kernel: [15601.254516]  [<ffffffff81233ce7>] ?=20
kobject_put+0x27/0x60
Dec  3 15:14:14 mail kernel: [15601.255590]  [<ffffffff8121b913>] ?=20
blk_queue_bio+0x2c3/0x410
Dec  3 15:14:14 mail kernel: [15601.256642]  [<ffffffff814171a6>] ?=20
retint_kernel+0x26/0x30
Dec  3 15:14:14 mail kernel: [15601.257679]  [<ffffffff814140bf>]=20
schedule+0x3f/0x60
Dec  3 15:14:14 mail kernel: [15601.258721]  [<ffffffffa0378209>]=20
get_active_stripe+0x2e9/0x600 [raid456]
Dec  3 15:14:14 mail kernel: [15601.259756]  [<ffffffff8105be20>] ?=20
try_to_wake_up+0x290/0x290
Dec  3 15:14:14 mail kernel: [15601.260792]  [<ffffffffa037559a>]=20
sync_request+0x35a/0x370 [raid456]
Dec  3 15:14:14 mail kernel: [15601.261838]  [<ffffffffa01c9a08>] ?=20
is_mddev_idle+0x128/0x140 [md_mod]
Dec  3 15:14:14 mail kernel: [15601.262867]  [<ffffffffa01cd2bf>]=20
md_do_sync+0x7ff/0xc70 [md_mod]
Dec  3 15:14:14 mail kernel: [15601.263895]  [<ffffffff81085750>] ?=20
abort_exclusive_wait+0xb0/0xb0
Dec  3 15:14:14 mail kernel: [15601.264926]  [<ffffffff810748cb>] ?=20
recalc_sigpending+0x1b/0x50
Dec  3 15:14:14 mail kernel: [15601.265972]  [<ffffffffa01c9dce>]=20
md_thread+0x10e/0x140 [md_mod]
Dec  3 15:14:14 mail kernel: [15601.267002]  [<ffffffffa01c9cc0>] ?=20
md_register_thread+0x110/0x110 [md_mod]
Dec  3 15:14:14 mail kernel: [15601.268033]  [<ffffffff81084e0c>]=20
kthread+0x8c/0xa0
Dec  3 15:14:14 mail kernel: [15601.269074]  [<ffffffff81419a34>]=20
kernel_thread_helper+0x4/0x10
Dec  3 15:14:14 mail kernel: [15601.270103]  [<ffffffff81084d80>] ?=20
kthread_worker_fn+0x190/0x190
Dec  3 15:14:14 mail kernel: [15601.271132]  [<ffffffff81419a30>] ?=20
gs_change+0x13/0x13
Dec  3 15:14:14 mail kernel: [15601.274249] loop0           D=20
000000010044b6c5     0  1729      2 0x00000000
Dec  3 15:14:14 mail kernel: [15601.275320]  ffff8801f9b31b30=20
0000000000000046 0000000000000000 0000000000000000
Dec  3 15:14:14 mail kernel: [15601.276385]  ffff880200950e40=20
ffff8801f9b31fd8 ffff8801f9b31fd8 ffff8801f9b31fd8
Dec  3 15:14:14 mail kernel: [15601.277454]  ffff880202cb7200=20
ffff880200950e40 0000000000000002 ffff8801f9b31b78
Dec  3 15:14:14 mail kernel: [15601.278536] Call Trace:
Dec  3 15:14:14 mail kernel: [15601.279594]  [<ffffffff81101a55>] ?=20
find_get_pages_tag+0x125/0x150
Dec  3 15:14:14 mail kernel: [15601.280671]  [<ffffffff8110e205>] ?=20
pagevec_lookup_tag+0x25/0x40
Dec  3 15:14:14 mail kernel: [15601.281736]  [<ffffffff8101d639>] ?=20
read_tsc+0x9/0x20
Dec  3 15:14:14 mail kernel: [15601.282801]  [<ffffffff8108f14d>] ?=20
ktime_get_ts+0xad/0xe0
Dec  3 15:14:14 mail kernel: [15601.283840]  [<ffffffff81101d60>] ?=20
__lock_page+0x70/0x70
Dec  3 15:14:14 mail kernel: [15601.284870]  [<ffffffff814140bf>]=20
schedule+0x3f/0x60
Dec  3 15:14:14 mail kernel: [15601.285902]  [<ffffffff8141416f>]=20
io_schedule+0x8f/0xd0
Dec  3 15:14:14 mail kernel: [15601.286919]  [<ffffffff81101d6e>]=20
sleep_on_page+0xe/0x20
Dec  3 15:14:14 mail kernel: [15601.287924]  [<ffffffff8141491f>]=20
__wait_on_bit+0x5f/0x90
Dec  3 15:14:14 mail kernel: [15601.288938]  [<ffffffff81101f58>]=20
wait_on_page_bit+0x78/0x80
Dec  3 15:14:14 mail kernel: [15601.289944]  [<ffffffff81085790>] ?=20
autoremove_wake_function+0x40/0x40
Dec  3 15:14:14 mail kernel: [15601.290953]  [<ffffffff811020cc>]=20
filemap_fdatawait_range+0x10c/0x1a0
Dec  3 15:14:14 mail kernel: [15601.291972]  [<ffffffff811030c8>]=20
filemap_write_and_wait_range+0x68/0x80
Dec  3 15:14:14 mail kernel: [15601.292985]  [<ffffffffa03a7234>]=20
xfs_file_fsync+0x54/0x340 [xfs]
Dec  3 15:14:14 mail kernel: [15601.293993]  [<ffffffff8119148b>]=20
vfs_fsync+0x2b/0x40
Dec  3 15:14:14 mail kernel: [15601.294993]  [<ffffffffa04dacf2>]=20
do_bio_filebacked+0x1b2/0x320 [loop]
Dec  3 15:14:14 mail kernel: [15601.296022]  [<ffffffffa050efac>] ?=20
end_workqueue_bio+0x9c/0xa0 [btrfs]
Dec  3 15:14:14 mail kernel: [15601.297029]  [<ffffffffa04daf1b>]=20
loop_thread+0xbb/0x260 [loop]
Dec  3 15:14:14 mail kernel: [15601.298032]  [<ffffffff81085750>] ?=20
abort_exclusive_wait+0xb0/0xb0
Dec  3 15:14:14 mail kernel: [15601.299049]  [<ffffffffa04dae60>] ?=20
do_bio_filebacked+0x320/0x320 [loop]
Dec  3 15:14:14 mail kernel: [15601.300057]  [<ffffffff81084e0c>]=20
kthread+0x8c/0xa0
Dec  3 15:14:14 mail kernel: [15601.301063]  [<ffffffff81419a34>]=20
kernel_thread_helper+0x4/0x10
Dec  3 15:14:14 mail kernel: [15601.302084]  [<ffffffff81084d80>] ?=20
kthread_worker_fn+0x190/0x190
Dec  3 15:14:14 mail kernel: [15601.303093]  [<ffffffff81419a30>] ?=20
gs_change+0x13/0x13
Dec  3 15:14:14 mail kernel: [15601.306162] btrfs-transacti D=20
ffff8801f9ab7200     0  1756      2 0x00000000
Dec  3 15:14:14 mail kernel: [15601.307205]  ffff8801e7533bc0=20
0000000000000046 ffff88020fc93400 0000000000000002
Dec  3 15:14:14 mail kernel: [15601.308257]  ffff8801f9ab7200=20
ffff8801e7533fd8 ffff8801e7533fd8 ffff8801e7533fd8
Dec  3 15:14:14 mail kernel: [15601.309327]  ffff880200950e40=20
ffff8801f9ab7200 ffff8801e7533b10 0000000081051ae2
Dec  3 15:14:14 mail kernel: [15601.310384] Call Trace:
Dec  3 15:14:14 mail kernel: [15601.311427]  [<ffffffff8105ad36>] ?=20
ttwu_do_activate.constprop.172+0x66/0x70
Dec  3 15:14:14 mail kernel: [15601.312509]  [<ffffffff8105bd6e>] ?=20
try_to_wake_up+0x1de/0x290
Dec  3 15:14:14 mail kernel: [15601.313568]  [<ffffffff814140bf>]=20
schedule+0x3f/0x60
Dec  3 15:14:14 mail kernel: [15601.314612]  [<ffffffff814147d5>]=20
schedule_timeout+0x305/0x390
Dec  3 15:14:14 mail kernel: [15601.315658]  [<ffffffff8104d003>] ?=20
__wake_up+0x53/0x70
Dec  3 15:14:14 mail kernel: [15601.316680]  [<ffffffff81413348>]=20
wait_for_common+0xc8/0x160
Dec  3 15:14:14 mail kernel: [15601.317699]  [<ffffffff8105be20>] ?=20
try_to_wake_up+0x290/0x290
Dec  3 15:14:14 mail kernel: [15601.318730]  [<ffffffff814133fd>]=20
wait_for_completion+0x1d/0x20
Dec  3 15:14:14 mail kernel: [15601.319745]  [<ffffffffa050f0bb>]=20
write_dev_flush+0x4b/0x140 [btrfs]
Dec  3 15:14:14 mail kernel: [15601.320760]  [<ffffffffa0511086>]=20
write_all_supers+0x6f6/0x800 [btrfs]
Dec  3 15:14:14 mail kernel: [15601.321791]  [<ffffffffa05111a3>]=20
write_ctree_super+0x13/0x20 [btrfs]
Dec  3 15:14:14 mail kernel: [15601.322809]  [<ffffffffa05164dd>]=20
btrfs_commit_transaction+0x63d/0x880 [btrfs]
Dec  3 15:14:14 mail kernel: [15601.323831]  [<ffffffff81085750>] ?=20
abort_exclusive_wait+0xb0/0xb0
Dec  3 15:14:14 mail kernel: [15601.324855]  [<ffffffffa0516b74>] ?=20
start_transaction+0x94/0x2b0 [btrfs]
Dec  3 15:14:14 mail kernel: [15601.325894]  [<ffffffffa050ed4d>]=20
transaction_kthread+0x26d/0x290 [btrfs]
Dec  3 15:14:14 mail kernel: [15601.326918]  [<ffffffffa050eae0>] ?=20
btrfs_congested_fn+0xd0/0xd0 [btrfs]
Dec  3 15:14:14 mail kernel: [15601.327937]  [<ffffffff81084e0c>]=20
kthread+0x8c/0xa0
Dec  3 15:14:14 mail kernel: [15601.328963]  [<ffffffff81419a34>]=20
kernel_thread_helper+0x4/0x10
Dec  3 15:14:14 mail kernel: [15601.329979]  [<ffffffff81084d80>] ?=20
kthread_worker_fn+0x190/0x190
Dec  3 15:14:14 mail kernel: [15601.330995]  [<ffffffff81419a30>] ?=20
gs_change+0x13/0x13
Dec  3 15:14:14 mail kernel: [15601.334083] flush-9:127     D=20
00000000a01fc200     0  1891      2 0x00000000
Dec  3 15:14:14 mail kernel: [15601.335141]  ffff880171771540=20
0000000000000046 0000000100000000 0000000300000001
Dec  3 15:14:14 mail kernel: [15601.336194]  ffff8802009d9c80=20
ffff880171771fd8 ffff880171771fd8 ffff880171771fd8
Dec  3 15:14:14 mail kernel: [15601.337252]  ffff8802009dc740=20
ffff8802009d9c80 ffff8801717714a0 ffffffff8104d003
Dec  3 15:14:14 mail kernel: [15601.338304] Call Trace:
Dec  3 15:14:14 mail kernel: [15601.339347]  [<ffffffff8104d003>] ?=20
__wake_up+0x53/0x70
Dec  3 15:14:14 mail kernel: [15601.340376]  [<ffffffff8114d48b>] ?=20
kfree+0x3b/0x170
Dec  3 15:14:14 mail kernel: [15601.341398]  [<ffffffffa01c732b>] ?=20
plugger_unplug+0x3b/0x50 [md_mod]
Dec  3 15:14:14 mail kernel: [15601.342432]  [<ffffffff8121b457>] ?=20
blk_flush_plug_list+0xa7/0x250
Dec  3 15:14:14 mail kernel: [15601.343453]  [<ffffffff814140bf>]=20
schedule+0x3f/0x60
Dec  3 15:14:14 mail kernel: [15601.344460]  [<ffffffffa0378209>]=20
get_active_stripe+0x2e9/0x600 [raid456]
Dec  3 15:14:14 mail kernel: [15601.345487]  [<ffffffffa01c6400>] ?=20
md_wakeup_thread+0x10/0x30 [md_mod]
Dec  3 15:14:14 mail kernel: [15601.346503]  [<ffffffff8105be20>] ?=20
try_to_wake_up+0x290/0x290
Dec  3 15:14:14 mail kernel: [15601.347519]  [<ffffffffa037be22>]=20
make_request+0x192/0x430 [raid456]
Dec  3 15:14:14 mail kernel: [15601.348555]  [<ffffffff81085750>] ?=20
abort_exclusive_wait+0xb0/0xb0
Dec  3 15:14:14 mail kernel: [15601.348559]  [<ffffffffa01c964a>]=20
md_make_request+0xfa/0x240 [md_mod]
Dec  3 15:14:14 mail kernel: [15601.348561]  [<ffffffff81219917>]=20
generic_make_request+0xc7/0x100
Dec  3 15:14:14 mail kernel: [15601.348563]  [<ffffffff812199d7>]=20
submit_bio+0x87/0x110
Dec  3 15:14:14 mail kernel: [15601.348565]  [<ffffffff8118b300>] ?=20
__mark_inode_dirty+0x40/0x230
Dec  3 15:14:14 mail kernel: [15601.348571]  [<ffffffffa03a16f7>]=20
xfs_submit_ioend_bio.isra.11+0x57/0x80 [xfs]
Dec  3 15:14:14 mail kernel: [15601.348578]  [<ffffffffa03a180e>]=20
xfs_submit_ioend+0xee/0x110 [xfs]
Dec  3 15:14:14 mail kernel: [15601.348585]  [<ffffffffa03a1a65>]=20
xfs_vm_writepage+0x235/0x530 [xfs]
Dec  3 15:14:14 mail kernel: [15601.348588]  [<ffffffff8110b75a>]=20
__writepage+0x1a/0x50
Dec  3 15:14:14 mail kernel: [15601.348591]  [<ffffffff8110bc21>]=20
write_cache_pages+0x1e1/0x4e0
Dec  3 15:14:14 mail kernel: [15601.348599]  [<ffffffffa03bab27>] ?=20
kmem_alloc+0x67/0xe0 [xfs]
Dec  3 15:14:14 mail kernel: [15601.348602]  [<ffffffff8110b740>] ?=20
bdi_set_max_ratio+0x90/0x90
Dec  3 15:14:14 mail kernel: [15601.348606]  [<ffffffff8110bf6d>]=20
generic_writepages+0x4d/0x70
Dec  3 15:14:14 mail kernel: [15601.348612]  [<ffffffffa03a06ad>]=20
xfs_vm_writepages+0x4d/0x60 [xfs]
Dec  3 15:14:14 mail kernel: [15601.348615]  [<ffffffff8110d6a4>]=20
do_writepages+0x24/0x40
Dec  3 15:14:14 mail kernel: [15601.348618]  [<ffffffff8118b76f>]=20
writeback_single_inode+0x10f/0x3f0
Dec  3 15:14:14 mail kernel: [15601.348621]  [<ffffffff8118be4a>]=20
writeback_sb_inodes+0x1aa/0x270
Dec  3 15:14:14 mail kernel: [15601.348624]  [<ffffffff8118bfae>]=20
__writeback_inodes_wb+0x9e/0xd0
Dec  3 15:14:14 mail kernel: [15601.348627]  [<ffffffff8118c5cb>]=20
wb_writeback+0x37b/0x3b0
Dec  3 15:14:14 mail kernel: [15601.348631]  [<ffffffff8117d562>] ?=20
get_nr_inodes+0x52/0x70
Dec  3 15:14:14 mail kernel: [15601.348634]  [<ffffffff8117e262>] ?=20
get_nr_dirty_inodes+0x52/0x80
Dec  3 15:14:14 mail kernel: [15601.348636]  [<ffffffff8118c69f>]=20
wb_check_old_data_flush+0x9f/0xb0
Dec  3 15:14:14 mail kernel: [15601.348639]  [<ffffffff8118db7c>]=20
wb_do_writeback+0x19c/0x230
Dec  3 15:14:14 mail kernel: [15601.348642]  [<ffffffff81414643>] ?=20
schedule_timeout+0x173/0x390
Dec  3 15:14:14 mail kernel: [15601.348645]  [<ffffffff81071b10>] ?=20
init_timer_deferrable_key+0x30/0x30
Dec  3 15:14:14 mail kernel: [15601.348648]  [<ffffffff8118dc9c>]=20
bdi_writeback_thread+0x8c/0x340
Dec  3 15:14:14 mail kernel: [15601.348651]  [<ffffffff8118dc10>] ?=20
wb_do_writeback+0x230/0x230
Dec  3 15:14:14 mail kernel: [15601.348654]  [<ffffffff81084e0c>]=20
kthread+0x8c/0xa0
Dec  3 15:14:14 mail kernel: [15601.348657]  [<ffffffff81419a34>]=20
kernel_thread_helper+0x4/0x10
Dec  3 15:14:14 mail kernel: [15601.348660]  [<ffffffff81084d80>] ?=20
kthread_worker_fn+0x190/0x190
Dec  3 15:14:14 mail kernel: [15601.348663]  [<ffffffff81419a30>] ?=20
gs_change+0x13/0x13
Dec  3 15:14:14 mail kernel: [15601.348669] smbd            D=20
000000010044b8d7     0  2058    823 0x00000004
Dec  3 15:14:14 mail kernel: [15601.348672]  ffff88005cf37a08=20
0000000000000082 ffff88005cf37938 ffffffff81371188
Dec  3 15:14:14 mail kernel: [15601.348676]  ffff8802012e63c0=20
ffff88005cf37fd8 ffff88005cf37fd8 ffff88005cf37fd8
Dec  3 15:14:14 mail kernel: [15601.348680]  ffff880202d21c80=20
ffff8802012e63c0 ffff8802012769c0 0000000000000246
Dec  3 15:14:14 mail kernel: [15601.348684] Call Trace:
Dec  3 15:14:14 mail kernel: [15601.348687]  [<ffffffff81371188>] ?=20
sch_direct_xmit+0x68/0x1d0
Dec  3 15:14:14 mail kernel: [15601.348691]  [<ffffffff81355a00>] ?=20
dev_queue_xmit+0x200/0x680
Dec  3 15:14:14 mail kernel: [15601.348694]  [<ffffffff81389200>] ?=20
ip_forward_options+0x1c0/0x1c0
Dec  3 15:14:14 mail kernel: [15601.348697]  [<ffffffff8138adbe>] ?=20
ip_finish_output+0x18e/0x310
Dec  3 15:14:14 mail kernel: [15601.348700]  [<ffffffff8101d639>] ?=20
read_tsc+0x9/0x20
Dec  3 15:14:14 mail kernel: [15601.348703]  [<ffffffff8108f14d>] ?=20
ktime_get_ts+0xad/0xe0
Dec  3 15:14:14 mail kernel: [15601.348705]  [<ffffffff81101d60>] ?=20
__lock_page+0x70/0x70
Dec  3 15:14:14 mail kernel: [15601.348708]  [<ffffffff814140bf>]=20
schedule+0x3f/0x60
Dec  3 15:14:14 mail kernel: [15601.348711]  [<ffffffff8141416f>]=20
io_schedule+0x8f/0xd0
Dec  3 15:14:14 mail kernel: [15601.348714]  [<ffffffff81101d6e>]=20
sleep_on_page+0xe/0x20
Dec  3 15:14:14 mail kernel: [15601.348716]  [<ffffffff8141491f>]=20
__wait_on_bit+0x5f/0x90
Dec  3 15:14:14 mail kernel: [15601.348719]  [<ffffffff81101f58>]=20
wait_on_page_bit+0x78/0x80
Dec  3 15:14:14 mail kernel: [15601.348722]  [<ffffffff81085790>] ?=20
autoremove_wake_function+0x40/0x40
Dec  3 15:14:14 mail kernel: [15601.348725]  [<ffffffff81102845>]=20
grab_cache_page_write_begin+0x95/0xe0
Dec  3 15:14:14 mail kernel: [15601.348732]  [<ffffffffa03a1150>] ?=20
xfs_get_blocks_direct+0x20/0x20 [xfs]
Dec  3 15:14:14 mail kernel: [15601.348736]  [<ffffffff811967b8>]=20
block_write_begin+0x38/0xa0
Dec  3 15:14:14 mail kernel: [15601.348743]  [<ffffffffa03a1213>]=20
xfs_vm_write_begin+0x43/0x70 [xfs]
Dec  3 15:14:14 mail kernel: [15601.348746]  [<ffffffff8110233c>]=20
generic_file_buffered_write+0x10c/0x270
Dec  3 15:14:14 mail kernel: [15601.348754]  [<ffffffffa03aad66>] ?=20
xfs_iunlock+0x116/0x180 [xfs]
Dec  3 15:14:14 mail kernel: [15601.348761]  [<ffffffffa03a7fef>]=20
xfs_file_buffered_aio_write+0x10f/0x200 [xfs]
Dec  3 15:14:14 mail kernel: [15601.348768]  [<ffffffffa03a8252>]=20
xfs_file_aio_write+0x172/0x2a0 [xfs]
Dec  3 15:14:14 mail kernel: [15601.348772]  [<ffffffff81162d62>]=20
do_sync_write+0xd2/0x110
Dec  3 15:14:14 mail kernel: [15601.348775]  [<ffffffff811f0fcc>] ?=20
security_file_permission+0x2c/0xb0
Dec  3 15:14:14 mail kernel: [15601.348778]  [<ffffffff81163311>] ?=20
rw_verify_area+0x61/0xf0
Dec  3 15:14:14 mail kernel: [15601.348781]  [<ffffffff8116366f>]=20
vfs_write+0xaf/0x180
Dec  3 15:14:14 mail kernel: [15601.348784]  [<ffffffff81163b12>]=20
sys_pwrite64+0x82/0xb0
Dec  3 15:14:14 mail kernel: [15601.348787]  [<ffffffff814178c2>]=20

system_call_fastpath+0x16/0x1b

Quoted 5 lines · Chris Mason

Quoted 4 lines · Tobias
Hi Chris!
Am 01.12.2011 19:41, schrieb Chris Mason:
Quoted 1 line
So, the transaction close is in btrfs_evict_inode, which sounds lik=

e a

Quoted 3 lines

Quoted 3 lines
Quoted 3 lines
deadlock recently fixed by this commit:
http://git.kernel.org/?p=3Dlinux/kernel/git/mason/linux-btrfs.git;a=

=3Dcommit;h=3Daa38a711a893accf5b5192f3d705a120deaa81e0

Quoted 2 lines

Quoted 2 lines
Quoted 2 lines
If you pull the for-linus branch from today, hopefully the problem =

will

Quoted 10 lines

Quoted 7 lines
Quoted 2 lines
be gone.
This looks very good. With this Kernel i still have some hangs, but only in rsync, only under high load and they don't lock up the system - so i guess it's ok now.
Thank You very much for Your help!
Glad to hear this is working. All the credit to Miao, who found the deadlock.

Quoted 7 lines

Quoted 1 line
When will this patches go into the main Kernel?
Linus pulled them in yesterday.
-chris
--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs=

" in

Quoted 2 lines

the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs" = in
the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Konstantinos Skarlatos

2011-12-02 15:22 UTC #9 lore raw

Re: Blocked for more than 120 seconds

In reply to Tobias

Hi all

Quoted 5 lines · Tobias

Hi Chris!
Am 01.12.2011 19:41, schrieb Chris Mason:
Quoted 2 lines
So, the transaction close is in btrfs_evict_inode, which sounds like=

Quoted 3 lines

Quoted 3 lines
deadlock recently fixed by this commit:
http://git.kernel.org/?p=3Dlinux/kernel/git/mason/linux-btrfs.git;a=3D=

commit;h=3Daa38a711a893accf5b5192f3d705a120deaa81e0=20

Quoted 3 lines

Quoted 3 lines
If you pull the for-linus branch from today, hopefully the problem w=

ill

Quoted 5 lines

Quoted 2 lines
be gone.
This looks very good. With this Kernel i still have some hangs, but=20 only in rsync, only under high load and they don't lock up the system=

=20

Quoted 1 line

- so i guess it's ok now.

I still have hangs and lock ups under the same situation (rsync of many= =20
files) under 3.2rc3. rc3 made the hang appear after 200gb of files,=20 while in rc2 i had hangs after only 11gb .

Quoted 9 lines

Thank You very much for Your help!
When will this patches go into the main Kernel?
Tobias
--=20
To unsubscribe from this list: send the line "unsubscribe linux-btrfs=

" in

Quoted 2 lines

the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs" = in
the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Tobias

author

2011-12-02 15:48 UTC #10 lore raw

Re: Blocked for more than 120 seconds

Am 02.12.2011 16:22, schrieb Konstantinos Skarlatos:

Quoted 6 lines

Quoted 6 lines
Quoted 6 lines
So, the transaction close is in btrfs_evict_inode, which sounds like a deadlock recently fixed by this commit:
http://git.kernel.org/?p=linux/kernel/git/mason/linux-btrfs.git;a=commit;h=aa38a711a893accf5b5192f3d705a120deaa81e0

Quoted 8 lines

Quoted 6 lines
Quoted 3 lines
If you pull the for-linus branch from today, hopefully the problem will be gone.
This looks very good. With this Kernel i still have some hangs, but only in rsync, only under high load and they don't lock up the system
- so i guess it's ok now.
I still have hangs and lock ups under the same situation (rsync of many files) under 3.2rc3. rc3 made the hang appear after 200gb of files, while in rc2 i had hangs after only 11gb .

Yes, i had them too in 3.2rc3! The problem where solved with patches from the "btrfs-for-linus" -branch. (see link above).

Tobias

Konstantinos Skarlatos

2011-12-02 19:53 UTC #11 lore raw

Re: Blocked for more than 120 seconds

I see they got into 3.2rc4, so I am now compiling it. I will report=20 back in a few hours

Quoted 2 lines · Tobias

Am 02.12.2011 16:22, schrieb Konstantinos Skarlatos:
Quoted 1 line
Quoted 1 line
Quoted 1 line
So, the transaction close is in btrfs_evict_inode, which sounds li=

ke a

Quoted 3 lines

Quoted 3 lines
Quoted 3 lines
Quoted 3 lines
deadlock recently fixed by this commit:
http://git.kernel.org/?p=3Dlinux/kernel/git/mason/linux-btrfs.git;=

a=3Dcommit;h=3Daa38a711a893accf5b5192f3d705a120deaa81e0=20

Quoted 3 lines

Quoted 3 lines
Quoted 3 lines
Quoted 3 lines
If you pull the for-linus branch from today, hopefully the problem=

=20

Quoted 5 lines

Quoted 5 lines
Quoted 5 lines
Quoted 3 lines
will
be gone.
This looks very good. With this Kernel i still have some hangs, but=

=20

Quoted 12 lines

Quoted 6 lines
Quoted 2 lines
only in rsync, only under high load and they don't lock up the=20 system - so i guess it's ok now.
I still have hangs and lock ups under the same situation (rsync of=20 many files) under 3.2rc3. rc3 made the hang appear after 200gb of=20 files, while in rc2 i had hangs after only 11gb .
Yes, i had them too in 3.2rc3! The problem where solved with patches=20 from the "btrfs-for-linus" -branch. (see link above).
Tobias

--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs" = in
the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Konstantinos Skarlatos

2011-12-03 00:35 UTC #12 lore raw

Re: Blocked for more than 120 seconds

After about 1TB of rsyncs from multiple servers at the same time, plus=20 some heavy filesystem loading, i believe that 3.2rc4 solves the problem= =20
for me. Now if only we had deduplication and an fsck tool :) On =CE=A0=CE=B1=CF=81=CE=B1=CF=83=CE=BA=CE=B5=CF=85=CE=AE, 2 =CE=94=CE=B5= =CE=BA=CE=AD=CE=BC=CE=B2=CF=81=CE=B9=CE=BF=CF=82 2011 9:53:10 =CE=BC=CE= =BC, Konstantinos Skarlatos=20

Quoted 4 lines · wrote:

I see they got into 3.2rc4, so I am now compiling it. I will report=20 back in a few hours
On =CE=A0=CE=B1=CF=81=CE=B1=CF=83=CE=BA=CE=B5=CF=85=CE=AE, 2 =CE=94=CE=

=B5=CE=BA=CE=AD=CE=BC=CE=B2=CF=81=CE=B9=CE=BF=CF=82 2011 5:48:31 =CE=BC=

Quoted 6 lines · Tobias

Quoted 6 lines
Am 02.12.2011 16:22, schrieb Konstantinos Skarlatos:
Quoted 5 lines
Quoted 5 lines
Quoted 5 lines
So, the transaction close is in btrfs_evict_inode, which sounds=20 like a
deadlock recently fixed by this commit:
http://git.kernel.org/?p=3Dlinux/kernel/git/mason/linux-btrfs.git=

;a=3Dcommit;h=3Daa38a711a893accf5b5192f3d705a120deaa81e0=20

Quoted 3 lines

Quoted 3 lines
Quoted 3 lines
Quoted 3 lines
Quoted 3 lines
If you pull the for-linus branch from today, hopefully the proble=

m=20

Quoted 5 lines

Quoted 5 lines
Quoted 5 lines
Quoted 5 lines
Quoted 3 lines
will
be gone.
This looks very good. With this Kernel i still have some hangs, bu=

t=20

Quoted 8 lines

Quoted 8 lines
Quoted 6 lines
Quoted 2 lines
only in rsync, only under high load and they don't lock up the=20 system - so i guess it's ok now.
I still have hangs and lock ups under the same situation (rsync of=20 many files) under 3.2rc3. rc3 made the hang appear after 200gb of=20 files, while in rc2 i had hangs after only 11gb .
Yes, i had them too in 3.2rc3! The problem where solved with patches=

=20

Quoted 4 lines

Quoted 4 lines
from the "btrfs-for-linus" -branch. (see link above).
Tobias

--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs" = in
the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Konstantinos Skarlatos

2011-12-03 14:36 UTC #13 lore raw

Re: Blocked for more than 120 seconds

unfortunately i was wrong. rc4 does not fix this issue for me when=20 rsyncing large amounts of data...

my mount options:
mount -o loop,compress=3Dzlib,compress-force btrfs_test /storage/btrfs the filesystem is a file on a raid5 xfs volume.

[15481.098588] INFO: task loop0:1729 blocked for more than 120 seconds.
[15481.099571] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[15481.100564] loop0           D 000000010044b6c5     0  1729      2=20
0x00000000
[15481.101550]  ffff8801f9b31b30 0000000000000046 0000000000000000=20
0000000000000000
[15481.102548]  ffff880200950e40 ffff8801f9b31fd8 ffff8801f9b31fd8=20
ffff8801f9b31fd8
[15481.103539]  ffff880202cb7200 ffff880200950e40 0000000000000002=20
ffff8801f9b31b78
[15481.104533] Call Trace:
[15481.105531]  [<ffffffff81101a55>] ? find_get_pages_tag+0x125/0x150
[15481.106541]  [<ffffffff8110e205>] ? pagevec_lookup_tag+0x25/0x40
[15481.107552]  [<ffffffff8101d639>] ? read_tsc+0x9/0x20
[15481.108576]  [<ffffffff8108f14d>] ? ktime_get_ts+0xad/0xe0
[15481.109592]  [<ffffffff81101d60>] ? __lock_page+0x70/0x70
[15481.110607]  [<ffffffff814140bf>] schedule+0x3f/0x60
[15481.111619]  [<ffffffff8141416f>] io_schedule+0x8f/0xd0
[15481.112641]  [<ffffffff81101d6e>] sleep_on_page+0xe/0x20
[15481.113639]  [<ffffffff8141491f>] __wait_on_bit+0x5f/0x90
[15481.114629]  [<ffffffff81101f58>] wait_on_page_bit+0x78/0x80
[15481.115628]  [<ffffffff81085790>] ?=20
autoremove_wake_function+0x40/0x40
[15481.116614]  [<ffffffff811020cc>] filemap_fdatawait_range+0x10c/0x1a=
0
[15481.117613]  [<ffffffff811030c8>]=20
filemap_write_and_wait_range+0x68/0x80
[15481.118630]  [<ffffffffa03a7234>] xfs_file_fsync+0x54/0x340 [xfs]
[15481.119629]  [<ffffffff8119148b>] vfs_fsync+0x2b/0x40
[15481.120627]  [<ffffffffa04dacf2>] do_bio_filebacked+0x1b2/0x320=20
[loop]
[15481.121645]  [<ffffffffa050efac>] ? end_workqueue_bio+0x9c/0xa0=20
[btrfs]
[15481.122668]  [<ffffffffa04daf1b>] loop_thread+0xbb/0x260 [loop]
[15481.123674]  [<ffffffff81085750>] ? abort_exclusive_wait+0xb0/0xb0
[15481.124676]  [<ffffffffa04dae60>] ? do_bio_filebacked+0x320/0x320=20
[loop]
[15481.125698]  [<ffffffff81084e0c>] kthread+0x8c/0xa0
[15481.126710]  [<ffffffff81419a34>] kernel_thread_helper+0x4/0x10
[15481.127721]  [<ffffffff81084d80>] ? kthread_worker_fn+0x190/0x190
[15481.128742]  [<ffffffff81419a30>] ? gs_change+0x13/0x13
[15481.129728] INFO: task btrfs-transacti:1756 blocked for more than=20
120 seconds.
[15481.130706] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[15481.131702] btrfs-transacti D ffff8801f9ab7200     0  1756      2=20
0x00000000
[15481.132723]  ffff8801e7533bc0 0000000000000046 ffff88020fc93400=20
0000000000000002
[15481.133744]  ffff8801f9ab7200 ffff8801e7533fd8 ffff8801e7533fd8=20
ffff8801e7533fd8
[15481.134771]  ffff880200950e40 ffff8801f9ab7200 ffff8801e7533b10=20
0000000081051ae2
[15481.135813] Call Trace:
[15481.136828]  [<ffffffff8105ad36>] ?=20
ttwu_do_activate.constprop.172+0x66/0x70
[15481.137863]  [<ffffffff8105bd6e>] ? try_to_wake_up+0x1de/0x290
[15481.138914]  [<ffffffff814140bf>] schedule+0x3f/0x60
[15481.139956]  [<ffffffff814147d5>] schedule_timeout+0x305/0x390
[15481.141007]  [<ffffffff8104d003>] ? __wake_up+0x53/0x70
[15481.142074]  [<ffffffff81413348>] wait_for_common+0xc8/0x160
[15481.143124]  [<ffffffff8105be20>] ? try_to_wake_up+0x290/0x290
[15481.144170]  [<ffffffff814133fd>] wait_for_completion+0x1d/0x20
[15481.145229]  [<ffffffffa050f0bb>] write_dev_flush+0x4b/0x140 [btrfs]
[15481.146275]  [<ffffffffa0511086>] write_all_supers+0x6f6/0x800=20
[btrfs]
[15481.147317]  [<ffffffffa05111a3>] write_ctree_super+0x13/0x20 [btrfs=
]
[15481.148354]  [<ffffffffa05164dd>]=20
btrfs_commit_transaction+0x63d/0x880 [btrfs]
[15481.149397]  [<ffffffff81085750>] ? abort_exclusive_wait+0xb0/0xb0
[15481.150416]  [<ffffffffa0516b74>] ? start_transaction+0x94/0x2b0=20
[btrfs]
[15481.151444]  [<ffffffffa050ed4d>] transaction_kthread+0x26d/0x290=20
[btrfs]
[15481.152492]  [<ffffffffa050eae0>] ? btrfs_congested_fn+0xd0/0xd0=20
[btrfs]
[15481.153519]  [<ffffffff81084e0c>] kthread+0x8c/0xa0
[15481.154542]  [<ffffffff81419a34>] kernel_thread_helper+0x4/0x10
[15481.155553]  [<ffffffff81084d80>] ? kthread_worker_fn+0x190/0x190
[15481.156522]  [<ffffffff81419a30>] ? gs_change+0x13/0x13
[15481.157501] INFO: task smbd:2058 blocked for more than 120 seconds.
[15481.158513] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[15481.159519] smbd            D 000000010044b8d7     0  2058    823=20
0x00000004
[15481.160544]  ffff88005cf37a08 0000000000000082 ffff88005cf37938=20
ffffffff81371188
[15481.161588]  ffff8802012e63c0 ffff88005cf37fd8 ffff88005cf37fd8=20
ffff88005cf37fd8
[15481.162658]  ffff880202d21c80 ffff8802012e63c0 ffff8802012769c0=20
0000000000000246
[15481.163708] Call Trace:
[15481.164736]  [<ffffffff81371188>] ? sch_direct_xmit+0x68/0x1d0
[15481.165781]  [<ffffffff81355a00>] ? dev_queue_xmit+0x200/0x680
[15481.166805]  [<ffffffff81389200>] ? ip_forward_options+0x1c0/0x1c0
[15481.167822]  [<ffffffff8138adbe>] ? ip_finish_output+0x18e/0x310
[15481.168850]  [<ffffffff8101d639>] ? read_tsc+0x9/0x20
[15481.169853]  [<ffffffff8108f14d>] ? ktime_get_ts+0xad/0xe0
[15481.170849]  [<ffffffff81101d60>] ? __lock_page+0x70/0x70
[15481.171858]  [<ffffffff814140bf>] schedule+0x3f/0x60
[15481.172851]  [<ffffffff8141416f>] io_schedule+0x8f/0xd0
[15481.173844]  [<ffffffff81101d6e>] sleep_on_page+0xe/0x20
[15481.174836]  [<ffffffff8141491f>] __wait_on_bit+0x5f/0x90
[15481.175845]  [<ffffffff81101f58>] wait_on_page_bit+0x78/0x80
[15481.176842]  [<ffffffff81085790>] ?=20
autoremove_wake_function+0x40/0x40
[15481.177845]  [<ffffffff81102845>]=20
grab_cache_page_write_begin+0x95/0xe0
[15481.178872]  [<ffffffffa03a1150>] ? xfs_get_blocks_direct+0x20/0x20=20
[xfs]
[15481.179888]  [<ffffffff811967b8>] block_write_begin+0x38/0xa0
[15481.180904]  [<ffffffffa03a1213>] xfs_vm_write_begin+0x43/0x70 [xfs]
[15481.181928]  [<ffffffff8110233c>]=20
generic_file_buffered_write+0x10c/0x270
[15481.182955]  [<ffffffffa03aad66>] ? xfs_iunlock+0x116/0x180 [xfs]
[15481.183979]  [<ffffffffa03a7fef>]=20
xfs_file_buffered_aio_write+0x10f/0x200 [xfs]
[15481.185011]  [<ffffffffa03a8252>] xfs_file_aio_write+0x172/0x2a0=20
[xfs]
[15481.186052]  [<ffffffff81162d62>] do_sync_write+0xd2/0x110
[15481.187073]  [<ffffffff811f0fcc>] ?=20
security_file_permission+0x2c/0xb0
[15481.188096]  [<ffffffff81163311>] ? rw_verify_area+0x61/0xf0
[15481.189127]  [<ffffffff8116366f>] vfs_write+0xaf/0x180
[15481.190141]  [<ffffffff81163b12>] sys_pwrite64+0x82/0xb0
[15481.191149]  [<ffffffff814178c2>] system_call_fastpath+0x16/0x1b
[15481.192171] INFO: task kworker/2:3:3713 blocked for more than 120=20
seconds.
[15481.193191] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[15481.194224] kworker/2:3     D 0000000000000000     0  3713      2=20
0x00000000
[15481.195273]  ffff880005d49cc0 0000000000000046 0000000246417c40=20
0000000800000000
[15481.196304]  ffff8802013eaac0 ffff880005d49fd8 ffff880005d49fd8=20
ffff880005d49fd8
[15481.197329]  ffff8802013eeae0 ffff8802013eaac0 ffff880005d49c20=20
ffffffffa03a3fcb
[15481.198345] Call Trace:
[15481.199365]  [<ffffffffa03a3fcb>] ? xfs_buf_iorequest+0x6b/0x100=20
[xfs]
[15481.200393]  [<ffffffffa03fa603>] ? xlog_bdstrat+0x23/0x60 [xfs]
[15481.201408]  [<ffffffffa03fb287>] ? xlog_sync+0x1d7/0x3c0 [xfs]
[15481.202419]  [<ffffffff814140bf>] schedule+0x3f/0x60
[15481.203418]  [<ffffffffa03fe62b>] _xfs_log_force_lsn+0x29b/0x2d0=20
[xfs]
[15481.204420]  [<ffffffff8105be20>] ? try_to_wake_up+0x290/0x290
[15481.205438]  [<ffffffffa03fa23b>] xfs_trans_commit+0x29b/0x2b0 [xfs]
[15481.206450]  [<ffffffffa03b4c60>] ? xfs_sync_inode_attr+0xf0/0xf0=20
[xfs]
[15481.207466]  [<ffffffffa03aa162>] xfs_fs_log_dummy+0x62/0x90 [xfs]
[15481.208486]  [<ffffffff8111ff90>] ? refresh_cpu_vm_stats+0x1a0/0x1a0
[15481.209504]  [<ffffffffa03b4ce4>] xfs_sync_worker+0x84/0x90 [xfs]
[15481.210518]  [<ffffffff8107f446>] process_one_work+0x116/0x4d0
[15481.211531]  [<ffffffff8107fdde>] worker_thread+0x15e/0x350
[15481.212559]  [<ffffffff8107fc80>] ?=20
manage_workers.isra.29+0x230/0x230
[15481.213573]  [<ffffffff81084e0c>] kthread+0x8c/0xa0
[15481.214577]  [<ffffffff81419a34>] kernel_thread_helper+0x4/0x10
[15481.215596]  [<ffffffff81084d80>] ? kthread_worker_fn+0x190/0x190
[15481.216600]  [<ffffffff81419a30>] ? gs_change+0x13/0x13
[15601.215172] INFO: task xfsbufd/md127:527 blocked for more than 120=20
seconds.
[15601.216198] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[15601.217226] xfsbufd/md127   D 00000001004562e8     0   527      2=20
0x00000000
[15601.218264]  ffff8801f912fab0 0000000000000046 0000000100000000=20
0000000300000001
[15601.219326]  ffff8802009dc740 ffff8801f912ffd8 ffff8801f912ffd8=20
ffff8801f912ffd8
[15601.220375]  ffffffff8180d020 ffff8802009dc740 ffff8801f912fa10=20
ffffffff8104d003
[15601.221411] Call Trace:
[15601.222441]  [<ffffffff8104d003>] ? __wake_up+0x53/0x70
[15601.223461]  [<ffffffff8114d48b>] ? kfree+0x3b/0x170
[15601.224479]  [<ffffffffa01c732b>] ? plugger_unplug+0x3b/0x50 [md_mod=
]
[15601.225507]  [<ffffffff8121b457>] ? blk_flush_plug_list+0xa7/0x250
[15601.226516]  [<ffffffff814140bf>] schedule+0x3f/0x60
[15601.227516]  [<ffffffffa0378209>] get_active_stripe+0x2e9/0x600=20
[raid456]
[15601.228540]  [<ffffffff8105be20>] ? try_to_wake_up+0x290/0x290
[15601.229552]  [<ffffffffa037be22>] make_request+0x192/0x430 [raid456]
[15601.230569]  [<ffffffff81085750>] ? abort_exclusive_wait+0xb0/0xb0
[15601.231588]  [<ffffffffa01c964a>] md_make_request+0xfa/0x240 [md_mod=
]
[15601.232628]  [<ffffffff811047a5>] ? mempool_alloc_slab+0x15/0x20
[15601.233654]  [<ffffffff81219917>] generic_make_request+0xc7/0x100
[15601.234682]  [<ffffffff812199d7>] submit_bio+0x87/0x110
[15601.235731]  [<ffffffffa03a3e6c>] _xfs_buf_ioapply+0x15c/0x1c0 [xfs]
[15601.236772]  [<ffffffffa03a4d75>] ? xfs_bdstrat_cb+0x65/0x120 [xfs]
[15601.237815]  [<ffffffffa03a3fb9>] xfs_buf_iorequest+0x59/0x100 [xfs]
[15601.238874]  [<ffffffffa03a4d75>] xfs_bdstrat_cb+0x65/0x120 [xfs]
[15601.239916]  [<ffffffffa03a4f3e>] xfsbufd+0x10e/0x170 [xfs]
[15601.240949]  [<ffffffff8105be32>] ? default_wake_function+0x12/0x20
[15601.241995]  [<ffffffffa03a4e30>] ? xfs_bdstrat_cb+0x120/0x120 [xfs]
[15601.243026]  [<ffffffff81084e0c>] kthread+0x8c/0xa0
[15601.244051]  [<ffffffff81419a34>] kernel_thread_helper+0x4/0x10
[15601.245076]  [<ffffffff81084d80>] ? kthread_worker_fn+0x190/0x190
[15601.246114]  [<ffffffff81419a30>] ? gs_change+0x13/0x13
[15601.247129] INFO: task md127_resync:529 blocked for more than 120=20
seconds.
[15601.248156] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[15601.249209] md127_resync    D 00000001004562fa     0   529      2=20
0x00000000
[15601.250259]  ffff8801f9073b80 0000000000000046 0000000100000000=20
ffffffff81233ce7
[15601.251316]  ffff8802013e8720 ffff8801f9073fd8 ffff8801f9073fd8=20
ffff8801f9073fd8
[15601.252392]  ffff880202cb4e60 ffff8802013e8720 ffff880200b70138=20
ffff880004bff300
[15601.253459] Call Trace:
[15601.254516]  [<ffffffff81233ce7>] ? kobject_put+0x27/0x60
[15601.255590]  [<ffffffff8121b913>] ? blk_queue_bio+0x2c3/0x410
[15601.256642]  [<ffffffff814171a6>] ? retint_kernel+0x26/0x30
[15601.257679]  [<ffffffff814140bf>] schedule+0x3f/0x60
[15601.258721]  [<ffffffffa0378209>] get_active_stripe+0x2e9/0x600=20
[raid456]
[15601.259756]  [<ffffffff8105be20>] ? try_to_wake_up+0x290/0x290
[15601.260792]  [<ffffffffa037559a>] sync_request+0x35a/0x370 [raid456]
[15601.261838]  [<ffffffffa01c9a08>] ? is_mddev_idle+0x128/0x140=20
[md_mod]
[15601.262867]  [<ffffffffa01cd2bf>] md_do_sync+0x7ff/0xc70 [md_mod]
[15601.263895]  [<ffffffff81085750>] ? abort_exclusive_wait+0xb0/0xb0
[15601.264926]  [<ffffffff810748cb>] ? recalc_sigpending+0x1b/0x50
[15601.265972]  [<ffffffffa01c9dce>] md_thread+0x10e/0x140 [md_mod]
[15601.267002]  [<ffffffffa01c9cc0>] ? md_register_thread+0x110/0x110=20
[md_mod]
[15601.268033]  [<ffffffff81084e0c>] kthread+0x8c/0xa0
[15601.269074]  [<ffffffff81419a34>] kernel_thread_helper+0x4/0x10
[15601.270103]  [<ffffffff81084d80>] ? kthread_worker_fn+0x190/0x190
[15601.271132]  [<ffffffff81419a30>] ? gs_change+0x13/0x13
[15601.272170] INFO: task loop0:1729 blocked for more than 120 seconds.
[15601.273202] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[15601.274249] loop0           D 000000010044b6c5     0  1729      2=20
0x00000000
[15601.275320]  ffff8801f9b31b30 0000000000000046 0000000000000000=20
0000000000000000
[15601.276385]  ffff880200950e40 ffff8801f9b31fd8 ffff8801f9b31fd8=20
ffff8801f9b31fd8
[15601.277454]  ffff880202cb7200 ffff880200950e40 0000000000000002=20
ffff8801f9b31b78
[15601.278536] Call Trace:
[15601.279594]  [<ffffffff81101a55>] ? find_get_pages_tag+0x125/0x150
[15601.280671]  [<ffffffff8110e205>] ? pagevec_lookup_tag+0x25/0x40
[15601.281736]  [<ffffffff8101d639>] ? read_tsc+0x9/0x20
[15601.282801]  [<ffffffff8108f14d>] ? ktime_get_ts+0xad/0xe0
[15601.283840]  [<ffffffff81101d60>] ? __lock_page+0x70/0x70
[15601.284870]  [<ffffffff814140bf>] schedule+0x3f/0x60
[15601.285902]  [<ffffffff8141416f>] io_schedule+0x8f/0xd0
[15601.286919]  [<ffffffff81101d6e>] sleep_on_page+0xe/0x20
[15601.287924]  [<ffffffff8141491f>] __wait_on_bit+0x5f/0x90
[15601.288938]  [<ffffffff81101f58>] wait_on_page_bit+0x78/0x80
[15601.289944]  [<ffffffff81085790>] ?=20
autoremove_wake_function+0x40/0x40
[15601.290953]  [<ffffffff811020cc>] filemap_fdatawait_range+0x10c/0x1a=
0
[15601.291972]  [<ffffffff811030c8>]=20
filemap_write_and_wait_range+0x68/0x80
[15601.292985]  [<ffffffffa03a7234>] xfs_file_fsync+0x54/0x340 [xfs]
[15601.293993]  [<ffffffff8119148b>] vfs_fsync+0x2b/0x40
[15601.294993]  [<ffffffffa04dacf2>] do_bio_filebacked+0x1b2/0x320=20
[loop]
[15601.296022]  [<ffffffffa050efac>] ? end_workqueue_bio+0x9c/0xa0=20
[btrfs]
[15601.297029]  [<ffffffffa04daf1b>] loop_thread+0xbb/0x260 [loop]
[15601.298032]  [<ffffffff81085750>] ? abort_exclusive_wait+0xb0/0xb0
[15601.299049]  [<ffffffffa04dae60>] ? do_bio_filebacked+0x320/0x320=20
[loop]
[15601.300057]  [<ffffffff81084e0c>] kthread+0x8c/0xa0
[15601.301063]  [<ffffffff81419a34>] kernel_thread_helper+0x4/0x10
[15601.302084]  [<ffffffff81084d80>] ? kthread_worker_fn+0x190/0x190
[15601.303093]  [<ffffffff81419a30>] ? gs_change+0x13/0x13
[15601.304098] INFO: task btrfs-transacti:1756 blocked for more than=20
120 seconds.
[15601.305126] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[15601.306162] btrfs-transacti D ffff8801f9ab7200     0  1756      2=20
0x00000000
[15601.307205]  ffff8801e7533bc0 0000000000000046 ffff88020fc93400=20
0000000000000002
[15601.308257]  ffff8801f9ab7200 ffff8801e7533fd8 ffff8801e7533fd8=20
ffff8801e7533fd8
[15601.309327]  ffff880200950e40 ffff8801f9ab7200 ffff8801e7533b10=20
0000000081051ae2
[15601.310384] Call Trace:
[15601.311427]  [<ffffffff8105ad36>] ?=20
ttwu_do_activate.constprop.172+0x66/0x70
[15601.312509]  [<ffffffff8105bd6e>] ? try_to_wake_up+0x1de/0x290
[15601.313568]  [<ffffffff814140bf>] schedule+0x3f/0x60
[15601.314612]  [<ffffffff814147d5>] schedule_timeout+0x305/0x390
[15601.315658]  [<ffffffff8104d003>] ? __wake_up+0x53/0x70
[15601.316680]  [<ffffffff81413348>] wait_for_common+0xc8/0x160
[15601.317699]  [<ffffffff8105be20>] ? try_to_wake_up+0x290/0x290
[15601.318730]  [<ffffffff814133fd>] wait_for_completion+0x1d/0x20
[15601.319745]  [<ffffffffa050f0bb>] write_dev_flush+0x4b/0x140 [btrfs]
[15601.320760]  [<ffffffffa0511086>] write_all_supers+0x6f6/0x800=20
[btrfs]
[15601.321791]  [<ffffffffa05111a3>] write_ctree_super+0x13/0x20 [btrfs=
]
[15601.322809]  [<ffffffffa05164dd>]=20
btrfs_commit_transaction+0x63d/0x880 [btrfs]
[15601.323831]  [<ffffffff81085750>] ? abort_exclusive_wait+0xb0/0xb0
[15601.324855]  [<ffffffffa0516b74>] ? start_transaction+0x94/0x2b0=20
[btrfs]
[15601.325894]  [<ffffffffa050ed4d>] transaction_kthread+0x26d/0x290=20
[btrfs]
[15601.326918]  [<ffffffffa050eae0>] ? btrfs_congested_fn+0xd0/0xd0=20
[btrfs]
[15601.327937]  [<ffffffff81084e0c>] kthread+0x8c/0xa0
[15601.328963]  [<ffffffff81419a34>] kernel_thread_helper+0x4/0x10
[15601.329979]  [<ffffffff81084d80>] ? kthread_worker_fn+0x190/0x190
[15601.330995]  [<ffffffff81419a30>] ? gs_change+0x13/0x13
[15601.332024] INFO: task flush-9:127:1891 blocked for more than 120=20
seconds.
[15601.333049] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[15601.334083] flush-9:127     D 00000000a01fc200     0  1891      2=20
0x00000000
[15601.335141]  ffff880171771540 0000000000000046 0000000100000000=20
0000000300000001
[15601.336194]  ffff8802009d9c80 ffff880171771fd8 ffff880171771fd8=20
ffff880171771fd8
[15601.337252]  ffff8802009dc740 ffff8802009d9c80 ffff8801717714a0=20
ffffffff8104d003
[15601.338304] Call Trace:
[15601.339347]  [<ffffffff8104d003>] ? __wake_up+0x53/0x70
[15601.340376]  [<ffffffff8114d48b>] ? kfree+0x3b/0x170
[15601.341398]  [<ffffffffa01c732b>] ? plugger_unplug+0x3b/0x50 [md_mod=
]
[15601.342432]  [<ffffffff8121b457>] ? blk_flush_plug_list+0xa7/0x250
[15601.343453]  [<ffffffff814140bf>] schedule+0x3f/0x60
[15601.344460]  [<ffffffffa0378209>] get_active_stripe+0x2e9/0x600=20
[raid456]
[15601.345487]  [<ffffffffa01c6400>] ? md_wakeup_thread+0x10/0x30=20
[md_mod]
[15601.346503]  [<ffffffff8105be20>] ? try_to_wake_up+0x290/0x290
[15601.347519]  [<ffffffffa037be22>] make_request+0x192/0x430 [raid456]
[15601.348555]  [<ffffffff81085750>] ? abort_exclusive_wait+0xb0/0xb0
[15601.348559]  [<ffffffffa01c964a>] md_make_request+0xfa/0x240 [md_mod=
]
[15601.348561]  [<ffffffff81219917>] generic_make_request+0xc7/0x100
[15601.348563]  [<ffffffff812199d7>] submit_bio+0x87/0x110
[15601.348565]  [<ffffffff8118b300>] ? __mark_inode_dirty+0x40/0x230
[15601.348571]  [<ffffffffa03a16f7>]=20
xfs_submit_ioend_bio.isra.11+0x57/0x80 [xfs]
[15601.348578]  [<ffffffffa03a180e>] xfs_submit_ioend+0xee/0x110 [xfs]
[15601.348585]  [<ffffffffa03a1a65>] xfs_vm_writepage+0x235/0x530 [xfs]
[15601.348588]  [<ffffffff8110b75a>] __writepage+0x1a/0x50
[15601.348591]  [<ffffffff8110bc21>] write_cache_pages+0x1e1/0x4e0
[15601.348599]  [<ffffffffa03bab27>] ? kmem_alloc+0x67/0xe0 [xfs]
[15601.348602]  [<ffffffff8110b740>] ? bdi_set_max_ratio+0x90/0x90
[15601.348606]  [<ffffffff8110bf6d>] generic_writepages+0x4d/0x70
[15601.348612]  [<ffffffffa03a06ad>] xfs_vm_writepages+0x4d/0x60 [xfs]
[15601.348615]  [<ffffffff8110d6a4>] do_writepages+0x24/0x40
[15601.348618]  [<ffffffff8118b76f>] writeback_single_inode+0x10f/0x3f0
[15601.348621]  [<ffffffff8118be4a>] writeback_sb_inodes+0x1aa/0x270
[15601.348624]  [<ffffffff8118bfae>] __writeback_inodes_wb+0x9e/0xd0
[15601.348627]  [<ffffffff8118c5cb>] wb_writeback+0x37b/0x3b0
[15601.348631]  [<ffffffff8117d562>] ? get_nr_inodes+0x52/0x70
[15601.348634]  [<ffffffff8117e262>] ? get_nr_dirty_inodes+0x52/0x80
[15601.348636]  [<ffffffff8118c69f>] wb_check_old_data_flush+0x9f/0xb0
[15601.348639]  [<ffffffff8118db7c>] wb_do_writeback+0x19c/0x230
[15601.348642]  [<ffffffff81414643>] ? schedule_timeout+0x173/0x390
[15601.348645]  [<ffffffff81071b10>] ?=20
init_timer_deferrable_key+0x30/0x30
[15601.348648]  [<ffffffff8118dc9c>] bdi_writeback_thread+0x8c/0x340
[15601.348651]  [<ffffffff8118dc10>] ? wb_do_writeback+0x230/0x230
[15601.348654]  [<ffffffff81084e0c>] kthread+0x8c/0xa0
[15601.348657]  [<ffffffff81419a34>] kernel_thread_helper+0x4/0x10
[15601.348660]  [<ffffffff81084d80>] ? kthread_worker_fn+0x190/0x190
[15601.348663]  [<ffffffff81419a30>] ? gs_change+0x13/0x13
[15601.348665] INFO: task smbd:2058 blocked for more than 120 seconds.
[15601.348667] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[15601.348669] smbd            D 000000010044b8d7     0  2058    823=20
0x00000004
[15601.348672]  ffff88005cf37a08 0000000000000082 ffff88005cf37938=20
ffffffff81371188
[15601.348676]  ffff8802012e63c0 ffff88005cf37fd8 ffff88005cf37fd8=20
ffff88005cf37fd8
[15601.348680]  ffff880202d21c80 ffff8802012e63c0 ffff8802012769c0=20
0000000000000246
[15601.348684] Call Trace:
[15601.348687]  [<ffffffff81371188>] ? sch_direct_xmit+0x68/0x1d0
[15601.348691]  [<ffffffff81355a00>] ? dev_queue_xmit+0x200/0x680
[15601.348694]  [<ffffffff81389200>] ? ip_forward_options+0x1c0/0x1c0
[15601.348697]  [<ffffffff8138adbe>] ? ip_finish_output+0x18e/0x310
[15601.348700]  [<ffffffff8101d639>] ? read_tsc+0x9/0x20
[15601.348703]  [<ffffffff8108f14d>] ? ktime_get_ts+0xad/0xe0
[15601.348705]  [<ffffffff81101d60>] ? __lock_page+0x70/0x70
[15601.348708]  [<ffffffff814140bf>] schedule+0x3f/0x60
[15601.348711]  [<ffffffff8141416f>] io_schedule+0x8f/0xd0
[15601.348714]  [<ffffffff81101d6e>] sleep_on_page+0xe/0x20
[15601.348716]  [<ffffffff8141491f>] __wait_on_bit+0x5f/0x90
[15601.348719]  [<ffffffff81101f58>] wait_on_page_bit+0x78/0x80
[15601.348722]  [<ffffffff81085790>] ?=20
autoremove_wake_function+0x40/0x40
[15601.348725]  [<ffffffff81102845>]=20
grab_cache_page_write_begin+0x95/0xe0
[15601.348732]  [<ffffffffa03a1150>] ? xfs_get_blocks_direct+0x20/0x20=20
[xfs]
[15601.348736]  [<ffffffff811967b8>] block_write_begin+0x38/0xa0
[15601.348743]  [<ffffffffa03a1213>] xfs_vm_write_begin+0x43/0x70 [xfs]
[15601.348746]  [<ffffffff8110233c>]=20
generic_file_buffered_write+0x10c/0x270
[15601.348754]  [<ffffffffa03aad66>] ? xfs_iunlock+0x116/0x180 [xfs]
[15601.348761]  [<ffffffffa03a7fef>]=20
xfs_file_buffered_aio_write+0x10f/0x200 [xfs]
[15601.348768]  [<ffffffffa03a8252>] xfs_file_aio_write+0x172/0x2a0=20
[xfs]
[15601.348772]  [<ffffffff81162d62>] do_sync_write+0xd2/0x110
[15601.348775]  [<ffffffff811f0fcc>] ?=20
security_file_permission+0x2c/0xb0
[15601.348778]  [<ffffffff81163311>] ? rw_verify_area+0x61/0xf0
[15601.348781]  [<ffffffff8116366f>] vfs_write+0xaf/0x180
[15601.348784]  [<ffffffff81163b12>] sys_pwrite64+0x82/0xb0
[15601.348787]  [<ffffffff814178c2>] system_call_fastpath+0x16/0x1b

Quoted 1 line · Konstan= tinos Skarlatos

After about 1TB of rsyncs from multiple servers at the same time, plu=

s=20

Quoted 3 lines

some heavy filesystem loading, i believe that 3.2rc4 solves the=20 problem for me. Now if only we had deduplication and an fsck tool :) On =CE=A0=CE=B1=CF=81=CE=B1=CF=83=CE=BA=CE=B5=CF=85=CE=AE, 2 =CE=94=CE=

=B5=CE=BA=CE=AD=CE=BC=CE=B2=CF=81=CE=B9=CE=BF=CF=82 2011 9:53:10 =CE=BC=

Quoted 4 lines · Konstantinos Skarlatos

Quoted 4 lines
I see they got into 3.2rc4, so I am now compiling it. I will report=20 back in a few hours
On =CE=A0=CE=B1=CF=81=CE=B1=CF=83=CE=BA=CE=B5=CF=85=CE=AE, 2 =CE=94=CE=

=B5=CE=BA=CE=AD=CE=BC=CE=B2=CF=81=CE=B9=CE=BF=CF=82 2011 5:48:31 =CE=BC=

Quoted 6 lines · Tobias

Quoted 6 lines
Quoted 6 lines
Am 02.12.2011 16:22, schrieb Konstantinos Skarlatos:
Quoted 5 lines
Quoted 5 lines
Quoted 5 lines
So, the transaction close is in btrfs_evict_inode, which sounds=20 like a
deadlock recently fixed by this commit:
http://git.kernel.org/?p=3Dlinux/kernel/git/mason/linux-btrfs.gi=

t;a=3Dcommit;h=3Daa38a711a893accf5b5192f3d705a120deaa81e0=20

Quoted 9 lines

Quoted 9 lines
Quoted 9 lines
Quoted 9 lines
Quoted 9 lines
Quoted 6 lines
If you pull the for-linus branch from today, hopefully the=20 problem will
be gone.
This looks very good. With this Kernel i still have some hangs,=20 but only in rsync, only under high load and they don't lock up th=

e=20

Quoted 3 lines

Quoted 3 lines
Quoted 3 lines
Quoted 3 lines
Quoted 1 line
system - so i guess it's ok now.
I still have hangs and lock ups under the same situation (rsync of=

=20

Quoted 4 lines

Quoted 4 lines
Quoted 4 lines
Quoted 2 lines
many files) under 3.2rc3. rc3 made the hang appear after 200gb of=20 files, while in rc2 i had hangs after only 11gb .
Yes, i had them too in 3.2rc3! The problem where solved with patche=

s=20

Quoted 4 lines

Quoted 4 lines
Quoted 4 lines
from the "btrfs-for-linus" -branch. (see link above).
Tobias

--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs" = in
the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

Chris Mason

2011-12-05 13:12 UTC #14 lore raw

Re: Blocked for more than 120 seconds

Quoted 6 lines · Konstantinos Skarlatos

unfortunately i was wrong. rc4 does not fix this issue for me when rsyncing large amounts of data...
my mount options:
mount -o loop,compress=zlib,compress-force btrfs_test /storage/btrfs the filesystem is a file on a raid5 xfs volume.

Oh, the loop + raid5 + xfs is going to cause problems. The loop driver is fine for testing but I wouldn't be using it in a production environment.

-chris

Konstantinos Skarlatos

2011-12-25 01:06 UTC #15 lore raw

Re: Blocked for more than 120 seconds

I got the same message on a new btrfs filesystem on a raid5 volume=20 (without loop this time). kernel is 3.2rc6
this happened after a day of rsyncing at about 10mbyte/sec, only way to= =20
reboot is with echo b > /proc/sysrq-trigger

[181201.285259] INFO: task btrfs-submit-1:768 blocked for more than 120=
=20
seconds.
[181201.285297] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[181201.285332] btrfs-submit-1  D 0000000021102920     0   768      2=20
0x00000000
[181201.285368]  ffff88006d1b7aa0 0000000000000046 0000000100000000=20
0000000300000001
[181201.285406]  ffff880072c64020 ffff88006d1b7fd8 ffff88006d1b7fd8=20
ffff88006d1b7fd8
[181201.285443]  ffff88006d900000 ffff880072c64020 ffff88006d1b7a00=20
ffffffff8104e053
[181201.285481] Call Trace:
[181201.285498]  [<ffffffff8104e053>] ? __wake_up+0x53/0x70
[181201.285524]  [<ffffffff8114e95b>] ? kfree+0x3b/0x170
[181201.285552]  [<ffffffffa053535b>] ? plugger_unplug+0x3b/0x50=20
[md_mod]
[181201.285583]  [<ffffffff8121ca57>] ? blk_flush_plug_list+0xa7/0x250
[181201.285612]  [<ffffffff814158bf>] schedule+0x3f/0x60
[181201.285637]  [<ffffffffa058b209>] get_active_stripe+0x2e9/0x600=20
[raid456]
[181201.285669]  [<ffffffffa0534400>] ? max_sync_store+0xc0/0xe0=20
[md_mod]
[181201.285700]  [<ffffffff8105cf10>] ? try_to_wake_up+0x290/0x290
[181201.285727]  [<ffffffffa058ee22>] make_request+0x192/0x430 [raid456=
]
[181201.285758]  [<ffffffff81086850>] ? abort_exclusive_wait+0xb0/0xb0
[181201.285787]  [<ffffffffa053752a>] md_make_request+0xfa/0x240=20
[md_mod]
[181201.285816]  [<ffffffff8114e95b>] ? kfree+0x3b/0x170
[181201.285840]  [<ffffffff8121af47>] generic_make_request+0xc7/0x100
[181201.285868]  [<ffffffff8121b007>] submit_bio+0x87/0x110
[181201.285900]  [<ffffffffa074dcfb>] run_scheduled_bios+0x26b/0x590=20
[btrfs]
[181201.285936]  [<ffffffffa074e035>] pending_bios_fn+0x15/0x20 [btrfs]
[181201.285969]  [<ffffffffa0754870>] worker_loop+0x150/0x520 [btrfs]
[181201.285997]  [<ffffffff8104c568>] ? __wake_up_common+0x58/0x90
[181201.286029]  [<ffffffffa0754720>] ? btrfs_queue_worker+0x300/0x300=20
[btrfs]
[181201.286060]  [<ffffffff81085f0c>] kthread+0x8c/0xa0
[181201.286084]  [<ffffffff8141b234>] kernel_thread_helper+0x4/0x10
[181201.286111]  [<ffffffff81085e80>] ? kthread_worker_fn+0x190/0x190
[181201.286139]  [<ffffffff8141b230>] ? gs_change+0x13/0x13
[181201.286164] INFO: task btrfs-transacti:780 blocked for more than=20
120 seconds.
[181201.286195] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[181201.286230] btrfs-transacti D 00000001033b48f7     0   780      2=20
0x00000000
[181201.286264]  ffff88006d1e9430 0000000000000046 ffff880000000000=20
ffffffff810146ef
[181201.286301]  ffff88006d905ca0 ffff88006d1e9fd8 ffff88006d1e9fd8=20
ffff88006d1e9fd8
[181201.286338]  ffff880073e97200 ffff88006d905ca0 ffff88006d1e9380=20
ffffffff8108cb65
[181201.287224] Call Trace:
[181201.288093]  [<ffffffff810146ef>] ? __switch_to+0xbf/0x2f0
[181201.288986]  [<ffffffff8108cb65>] ? sched_clock_local+0x25/0x90
[181201.289867]  [<ffffffffa0726640>] ? btrfs_buffer_uptodate+0x50/0x70=
=20
[btrfs]
[181201.290744]  [<ffffffffa070c48c>] ? comp_keys+0x2c/0x30 [btrfs]
[181201.291613]  [<ffffffff814158bf>] schedule+0x3f/0x60
[181201.292470]  [<ffffffffa058b209>] get_active_stripe+0x2e9/0x600=20
[raid456]
[181201.293317]  [<ffffffff8105cf10>] ? try_to_wake_up+0x290/0x290
[181201.294170]  [<ffffffffa058ee22>] make_request+0x192/0x430 [raid456=
]
[181201.295030]  [<ffffffff81086850>] ? abort_exclusive_wait+0xb0/0xb0
[181201.295897]  [<ffffffffa053752a>] md_make_request+0xfa/0x240=20
[md_mod]
[181201.296764]  [<ffffffffa074e14e>] ? __btrfs_map_block+0x10e/0x840=20
[btrfs]
[181201.297620]  [<ffffffff8121af47>] generic_make_request+0xc7/0x100
[181201.298463]  [<ffffffff8121b007>] submit_bio+0x87/0x110
[181201.299303]  [<ffffffffa0751ebe>] btrfs_map_bio+0x13e/0x1d0 [btrfs]
[181201.300137]  [<ffffffffa072d799>] btrfs_submit_bio_hook+0xa9/0x170=20
[btrfs]
[181201.300966]  [<ffffffff81199eb1>] ?=20
__bio_add_page.part.14+0x101/0x240
[181201.301803]  [<ffffffffa0745c9a>] submit_one_bio+0x6a/0xa0 [btrfs]
[181201.302644]  [<ffffffffa07492fd>]=20
submit_extent_page.isra.28+0xdd/0x200 [btrfs]
[181201.302651]  [<ffffffffa074a0ac>] __extent_writepage+0x52c/0x740=20
[btrfs]
[181201.302658]  [<ffffffffa0746e80>] ? clear_extent_bit+0x3d0/0x3d0=20
[btrfs]
[181201.302666]  [<ffffffffa074a58a>]=20
extent_write_cache_pages.isra.22.constprop.30+0x2ca/0x3f0 [btrfs]
[181201.302674]  [<ffffffffa074a8f5>] extent_writepages+0x45/0x60=20
[btrfs]
[181201.302681]  [<ffffffffa072f780>] ?=20
uncompress_inline.isra.47+0x1d0/0x1d0 [btrfs]
[181201.302687]  [<ffffffffa0746c7a>] ? clear_extent_bit+0x1ca/0x3d0=20
[btrfs]
[181201.302694]  [<ffffffffa072ea68>] btrfs_writepages+0x28/0x30 [btrfs=
]
[181201.302697]  [<ffffffff8110eb64>] do_writepages+0x24/0x40
[181201.302700]  [<ffffffff811043cb>]=20
__filemap_fdatawrite_range+0x5b/0x60
[181201.302702]  [<ffffffff811043ef>] filemap_fdatawrite+0x1f/0x30
[181201.302704]  [<ffffffff81104435>] filemap_write_and_wait+0x35/0x60
[181201.302711]  [<ffffffffa07616c7>]=20
__btrfs_write_out_cache+0x807/0xa80 [btrfs]
[181201.302717]  [<ffffffffa0767008>] ?=20
btrfs_find_ref_cluster+0x68/0x190 [btrfs]
[181201.302723]  [<ffffffffa07619d5>] btrfs_write_out_cache+0x95/0xf0=20
[btrfs]
[181201.302729]  [<ffffffffa071abe1>]=20
btrfs_write_dirty_block_groups+0x481/0x580 [btrfs]
[181201.302736]  [<ffffffffa0729c05>] commit_cowonly_roots+0x115/0x1e0=20
[btrfs]
[181201.302742]  [<ffffffffa072b3ec>]=20
btrfs_commit_transaction+0x3fc/0x880 [btrfs]
[181201.302745]  [<ffffffff81086850>] ? abort_exclusive_wait+0xb0/0xb0
[181201.302751]  [<ffffffffa072bcc4>] ? start_transaction+0x94/0x2b0=20
[btrfs]
[181201.302758]  [<ffffffffa0723e6d>] transaction_kthread+0x26d/0x290=20
[btrfs]
[181201.302764]  [<ffffffffa0723c00>] ? btrfs_congested_fn+0xd0/0xd0=20
[btrfs]
[181201.302766]  [<ffffffff81085f0c>] kthread+0x8c/0xa0
[181201.302768]  [<ffffffff8141b234>] kernel_thread_helper+0x4/0x10
[181201.302770]  [<ffffffff81085e80>] ? kthread_worker_fn+0x190/0x190
[181201.302772]  [<ffffffff8141b230>] ? gs_change+0x13/0x13
[181201.302775] INFO: task rsync:30933 blocked for more than 120=20
seconds.
[181201.302776] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[181201.302777] rsync           D 00000001033b48f2     0 30933  30932=20
0x00000000
[181201.302779]  ffff880072ce5b98 0000000000000082 0000000000000000=20
0000000000000001
[181201.302781]  ffff88006d9023a0 ffff880072ce5fd8 ffff880072ce5fd8=20
ffff880072ce5fd8
[181201.302783]  ffffffff8180d020 ffff88006d9023a0 ffffffff81177b50=20
00000000000000db
[181201.302785] Call Trace:
[181201.302788]  [<ffffffff81177b50>] ? poll_freewait+0xe0/0xe0
[181201.302790]  [<ffffffff81177c40>] ? __pollwait+0xf0/0xf0
[181201.302792]  [<ffffffff81051970>] ? select_task_rq_fair+0x540/0xa60
[181201.302794]  [<ffffffff814158bf>] schedule+0x3f/0x60
[181201.302800]  [<ffffffffa072a705>]=20
wait_current_trans.isra.22+0xa5/0xf0 [btrfs]
[181201.302803]  [<ffffffff81086850>] ? abort_exclusive_wait+0xb0/0xb0
[181201.302809]  [<ffffffffa072be20>] start_transaction+0x1f0/0x2b0=20
[btrfs]
[181201.302816]  [<ffffffffa072bf35>] btrfs_join_transaction+0x15/0x20=20
[btrfs]
[181201.302823]  [<ffffffffa0736980>] btrfs_dirty_inode+0x50/0xd0=20
[btrfs]
[181201.302830]  [<ffffffffa0736c86>] btrfs_update_time+0xd6/0x170=20
[btrfs]
[181201.302837]  [<ffffffffa073aee8>] btrfs_file_aio_write+0x1c8/0x520=20
[btrfs]
[181201.302840]  [<ffffffff8116e8f2>] ? pipe_read+0x2d2/0x4e0
[181201.302842]  [<ffffffff81164302>] do_sync_write+0xd2/0x110
[181201.302844]  [<ffffffff81051019>] ? finish_task_switch+0x49/0xd0
[181201.302848]  [<ffffffff811f266c>] ?=20
security_file_permission+0x2c/0xb0
[181201.302849]  [<ffffffff811648b1>] ? rw_verify_area+0x61/0xf0
[181201.302851]  [<ffffffff81164c0f>] vfs_write+0xaf/0x180
[181201.302853]  [<ffffffff81164f3a>] sys_write+0x4a/0x90
[181201.302856]  [<ffffffff814190c2>] system_call_fastpath+0x16/0x1b
[181201.302858] INFO: task flush-btrfs-1:30940 blocked for more than=20
120 seconds.
[181201.302859] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[181201.302860] flush-btrfs-1   D 00000001033b5a85     0 30940      2=20
0x00000000
[181201.302862]  ffff8800236218d0 0000000000000046 ffff880000000000=20
ffffffffa075460e
[181201.302864]  ffff88007222b1e0 ffff880023621fd8 ffff880023621fd8=20
ffff880023621fd8
[181201.302866]  ffff880073e97200 ffff88007222b1e0 ffff88000dad1550=20
ffff880023621870
[181201.302868] Call Trace:
[181201.302874]  [<ffffffffa075460e>] ? btrfs_queue_worker+0x1ee/0x300=20
[btrfs]
[181201.302881]  [<ffffffffa07330b5>] ? run_delalloc_range+0x185/0x360=20
[btrfs]
[181201.302883]  [<ffffffff8101d639>] ? read_tsc+0x9/0x20
[181201.302885]  [<ffffffff81103140>] ? __lock_page+0x70/0x70
[181201.302887]  [<ffffffff814158bf>] schedule+0x3f/0x60
[181201.302889]  [<ffffffff8141596f>] io_schedule+0x8f/0xd0
[181201.302891]  [<ffffffff8110314e>] sleep_on_page+0xe/0x20
[181201.302892]  [<ffffffff8141623a>] __wait_on_bit_lock+0x5a/0xc0
[181201.302894]  [<ffffffff81103137>] __lock_page+0x67/0x70
[181201.302897]  [<ffffffff81086890>] ?=20
autoremove_wake_function+0x40/0x40
[181201.302903]  [<ffffffffa074a4d5>]=20
extent_write_cache_pages.isra.22.constprop.30+0x215/0x3f0 [btrfs]
[181201.302911]  [<ffffffffa074a8f5>] extent_writepages+0x45/0x60=20
[btrfs]
[181201.302917]  [<ffffffffa072f780>] ?=20
uncompress_inline.isra.47+0x1d0/0x1d0 [btrfs]
[181201.302924]  [<ffffffffa072ea68>] btrfs_writepages+0x28/0x30 [btrfs=
]
[181201.302926]  [<ffffffff8110eb64>] do_writepages+0x24/0x40
[181201.302928]  [<ffffffff8118ce0f>] writeback_single_inode+0x10f/0x3f=
0
[181201.302930]  [<ffffffff8118d4ea>] writeback_sb_inodes+0x1aa/0x270
[181201.302932]  [<ffffffff8118d64e>] __writeback_inodes_wb+0x9e/0xd0
[181201.302934]  [<ffffffff8118dc6b>] wb_writeback+0x37b/0x3b0
[181201.302937]  [<ffffffff8117ebd2>] ? get_nr_inodes+0x52/0x70
[181201.302939]  [<ffffffff8117f8d2>] ? get_nr_dirty_inodes+0x52/0x80
[181201.302941]  [<ffffffff8118dd3f>] wb_check_old_data_flush+0x9f/0xb0
[181201.302943]  [<ffffffff8118f21c>] wb_do_writeback+0x19c/0x230
[181201.302944]  [<ffffffff81415e43>] ? schedule_timeout+0x173/0x390
[181201.302947]  [<ffffffff81072c10>] ?=20
init_timer_deferrable_key+0x30/0x30
[181201.302949]  [<ffffffff8118f33c>] bdi_writeback_thread+0x8c/0x340
[181201.302951]  [<ffffffff8118f2b0>] ? wb_do_writeback+0x230/0x230
[181201.302953]  [<ffffffff81085f0c>] kthread+0x8c/0xa0
[181201.302955]  [<ffffffff8141b234>] kernel_thread_helper+0x4/0x10
[181201.302957]  [<ffffffff81085e80>] ? kthread_worker_fn+0x190/0x190
[181201.302959]  [<ffffffff8141b230>] ? gs_change+0x13/0x13
[181201.302960] INFO: task btrfs-delalloc-:30957 blocked for more than=20
120 seconds.
[181201.302962] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[181201.302963] btrfs-delalloc- D 00000001033b5a86     0 30957      2=20
0x00000000
[181201.302965]  ffff88005147fc50 0000000000000046 0080004000000000=20
0800040002000100
[181201.302967]  ffff880072ab8e40 ffff88005147ffd8 ffff88005147ffd8=20
ffff88005147ffd8
[181201.302969]  ffff880073f09c80 ffff880072ab8e40 0000000000000001=20
0000000000000000
[181201.302970] Call Trace:
[181201.302973]  [<ffffffffa06fea84>] ? zlib_tr_flush_block+0x5f4/0x6f0=
=20
[zlib_deflate]
[181201.302975]  [<ffffffffa06fb6cc>] ? flush_pending+0x4c/0x90=20
[zlib_deflate]
[181201.302978]  [<ffffffffa06fb6cc>] ? flush_pending+0x4c/0x90=20
[zlib_deflate]
[181201.302980]  [<ffffffffa06fc506>] ? zlib_deflate+0x1b6/0x410=20
[zlib_deflate]
[181201.302982]  [<ffffffff814158bf>] schedule+0x3f/0x60
[181201.302988]  [<ffffffffa072a705>]=20
wait_current_trans.isra.22+0xa5/0xf0 [btrfs]
[181201.302990]  [<ffffffff81086850>] ? abort_exclusive_wait+0xb0/0xb0
[181201.302997]  [<ffffffffa072be20>] start_transaction+0x1f0/0x2b0=20
[btrfs]
[181201.303003]  [<ffffffffa072bf35>] btrfs_join_transaction+0x15/0x20=20
[btrfs]
[181201.303010]  [<ffffffffa0733a55>] compress_file_range+0x2c5/0x660=20
[btrfs]
[181201.303017]  [<ffffffffa0733e25>] async_cow_start+0x35/0x50 [btrfs]
[181201.303023]  [<ffffffffa0754870>] worker_loop+0x150/0x520 [btrfs]
[181201.303029]  [<ffffffffa0754720>] ? btrfs_queue_worker+0x300/0x300=20
[btrfs]
[181201.303032]  [<ffffffff81085f0c>] kthread+0x8c/0xa0
[181201.303033]  [<ffffffff8141b234>] kernel_thread_helper+0x4/0x10
[181201.303036]  [<ffffffff81085e80>] ? kthread_worker_fn+0x190/0x190
[181201.303037]  [<ffffffff8141b230>] ? gs_change+0x13/0x13
[181321.301930] INFO: task btrfs-submit-1:768 blocked for more than 120=
=20
seconds.
[181321.302761] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[181321.303594] btrfs-submit-1  D 0000000021102920     0   768      2=20
0x00000000
[181321.304428]  ffff88006d1b7aa0 0000000000000046 0000000100000000=20
0000000300000001
[181321.305272]  ffff880072c64020 ffff88006d1b7fd8 ffff88006d1b7fd8=20
ffff88006d1b7fd8
[181321.306110]  ffff88006d900000 ffff880072c64020 ffff88006d1b7a00=20
ffffffff8104e053
[181321.306940] Call Trace:
[181321.307759]  [<ffffffff8104e053>] ? __wake_up+0x53/0x70
[181321.308595]  [<ffffffff8114e95b>] ? kfree+0x3b/0x170
[181321.309428]  [<ffffffffa053535b>] ? plugger_unplug+0x3b/0x50=20
[md_mod]
[181321.310266]  [<ffffffff8121ca57>] ? blk_flush_plug_list+0xa7/0x250
[181321.311107]  [<ffffffff814158bf>] schedule+0x3f/0x60
[181321.311951]  [<ffffffffa058b209>] get_active_stripe+0x2e9/0x600=20
[raid456]
[181321.312805]  [<ffffffffa0534400>] ? max_sync_store+0xc0/0xe0=20
[md_mod]
[181321.313657]  [<ffffffff8105cf10>] ? try_to_wake_up+0x290/0x290
[181321.314510]  [<ffffffffa058ee22>] make_request+0x192/0x430 [raid456=
]
[181321.315376]  [<ffffffff81086850>] ? abort_exclusive_wait+0xb0/0xb0
[181321.316234]  [<ffffffffa053752a>] md_make_request+0xfa/0x240=20
[md_mod]
[181321.317094]  [<ffffffff8114e95b>] ? kfree+0x3b/0x170
[181321.317952]  [<ffffffff8121af47>] generic_make_request+0xc7/0x100
[181321.318821]  [<ffffffff8121b007>] submit_bio+0x87/0x110
[181321.319690]  [<ffffffffa074dcfb>] run_scheduled_bios+0x26b/0x590=20
[btrfs]
[181321.320564]  [<ffffffffa074e035>] pending_bios_fn+0x15/0x20 [btrfs]
[181321.321441]  [<ffffffffa0754870>] worker_loop+0x150/0x520 [btrfs]
[181321.322311]  [<ffffffff8104c568>] ? __wake_up_common+0x58/0x90
[181321.323167]  [<ffffffffa0754720>] ? btrfs_queue_worker+0x300/0x300=20
[btrfs]
[181321.324015]  [<ffffffff81085f0c>] kthread+0x8c/0xa0
[181321.324856]  [<ffffffff8141b234>] kernel_thread_helper+0x4/0x10
[181321.325700]  [<ffffffff81085e80>] ? kthread_worker_fn+0x190/0x190
[181321.326537]  [<ffffffff8141b230>] ? gs_change+0x13/0x13
[181321.327360] INFO: task btrfs-transacti:780 blocked for more than=20
120 seconds.
[181321.328189] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[181321.329035] btrfs-transacti D 00000001033b48f7     0   780      2=20
0x00000000
[181321.329900]  ffff88006d1e9430 0000000000000046 ffff880000000000=20
ffffffff810146ef
[181321.330774]  ffff88006d905ca0 ffff88006d1e9fd8 ffff88006d1e9fd8=20
ffff88006d1e9fd8
[181321.331646]  ffff880073e97200 ffff88006d905ca0 ffff88006d1e9380=20
ffffffff8108cb65
[181321.332527] Call Trace:
[181321.333375]  [<ffffffff810146ef>] ? __switch_to+0xbf/0x2f0
[181321.334238]  [<ffffffff8108cb65>] ? sched_clock_local+0x25/0x90
[181321.335104]  [<ffffffffa0726640>] ? btrfs_buffer_uptodate+0x50/0x70=
=20
[btrfs]
[181321.335980]  [<ffffffffa070c48c>] ? comp_keys+0x2c/0x30 [btrfs]
[181321.336843]  [<ffffffff814158bf>] schedule+0x3f/0x60
[181321.337704]  [<ffffffffa058b209>] get_active_stripe+0x2e9/0x600=20
[raid456]
[181321.338581]  [<ffffffff8105cf10>] ? try_to_wake_up+0x290/0x290
[181321.339447]  [<ffffffffa058ee22>] make_request+0x192/0x430 [raid456=
]
[181321.340320]  [<ffffffff81086850>] ? abort_exclusive_wait+0xb0/0xb0
[181321.341194]  [<ffffffffa053752a>] md_make_request+0xfa/0x240=20
[md_mod]
[181321.342084]  [<ffffffffa074e14e>] ? __btrfs_map_block+0x10e/0x840=20
[btrfs]
[181321.342958]  [<ffffffff8121af47>] generic_make_request+0xc7/0x100
[181321.343818]  [<ffffffff8121b007>] submit_bio+0x87/0x110
[181321.344668]  [<ffffffffa0751ebe>] btrfs_map_bio+0x13e/0x1d0 [btrfs]
[181321.345524]  [<ffffffffa072d799>] btrfs_submit_bio_hook+0xa9/0x170=20
[btrfs]
[181321.346365]  [<ffffffff81199eb1>] ?=20
__bio_add_page.part.14+0x101/0x240
[181321.347216]  [<ffffffffa0745c9a>] submit_one_bio+0x6a/0xa0 [btrfs]
[181321.348059]  [<ffffffffa07492fd>]=20
submit_extent_page.isra.28+0xdd/0x200 [btrfs]
[181321.348912]  [<ffffffffa074a0ac>] __extent_writepage+0x52c/0x740=20
[btrfs]
[181321.349763]  [<ffffffffa0746e80>] ? clear_extent_bit+0x3d0/0x3d0=20
[btrfs]
[181321.350613]  [<ffffffffa074a58a>]=20
extent_write_cache_pages.isra.22.constprop.30+0x2ca/0x3f0 [btrfs]
[181321.351480]  [<ffffffffa074a8f5>] extent_writepages+0x45/0x60=20
[btrfs]
[181321.352351]  [<ffffffffa072f780>] ?=20
uncompress_inline.isra.47+0x1d0/0x1d0 [btrfs]
[181321.353220]  [<ffffffffa0746c7a>] ? clear_extent_bit+0x1ca/0x3d0=20
[btrfs]
[181321.354089]  [<ffffffffa072ea68>] btrfs_writepages+0x28/0x30 [btrfs=
]
[181321.354955]  [<ffffffff8110eb64>] do_writepages+0x24/0x40
[181321.355823]  [<ffffffff811043cb>]=20
__filemap_fdatawrite_range+0x5b/0x60
[181321.356688]  [<ffffffff811043ef>] filemap_fdatawrite+0x1f/0x30
[181321.357546]  [<ffffffff81104435>] filemap_write_and_wait+0x35/0x60
[181321.358408]  [<ffffffffa07616c7>]=20
__btrfs_write_out_cache+0x807/0xa80 [btrfs]
[181321.359281]  [<ffffffffa0767008>] ?=20
btrfs_find_ref_cluster+0x68/0x190 [btrfs]
[181321.360147]  [<ffffffffa07619d5>] btrfs_write_out_cache+0x95/0xf0=20
[btrfs]
[181321.361012]  [<ffffffffa071abe1>]=20
btrfs_write_dirty_block_groups+0x481/0x580 [btrfs]
[181321.361888]  [<ffffffffa0729c05>] commit_cowonly_roots+0x115/0x1e0=20
[btrfs]
[181321.362759]  [<ffffffffa072b3ec>]=20
btrfs_commit_transaction+0x3fc/0x880 [btrfs]
[181321.363632]  [<ffffffff81086850>] ? abort_exclusive_wait+0xb0/0xb0
[181321.364508]  [<ffffffffa072bcc4>] ? start_transaction+0x94/0x2b0=20
[btrfs]
[181321.365388]  [<ffffffffa0723e6d>] transaction_kthread+0x26d/0x290=20
[btrfs]
[181321.366265]  [<ffffffffa0723c00>] ? btrfs_congested_fn+0xd0/0xd0=20
[btrfs]
[181321.367138]  [<ffffffff81085f0c>] kthread+0x8c/0xa0
[181321.368005]  [<ffffffff8141b234>] kernel_thread_helper+0x4/0x10
[181321.368875]  [<ffffffff81085e80>] ? kthread_worker_fn+0x190/0x190
[181321.369726]  [<ffffffff8141b230>] ? gs_change+0x13/0x13
[181321.370560] INFO: task rsync:30933 blocked for more than 120=20
seconds.
[181321.371399] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[181321.372258] rsync           D 00000001033b48f2     0 30933  30932=20
0x00000000
[181321.373125]  ffff880072ce5b98 0000000000000082 0000000000000000=20
0000000000000001
[181321.373990]  ffff88006d9023a0 ffff880072ce5fd8 ffff880072ce5fd8=20
ffff880072ce5fd8
[181321.374857]  ffffffff8180d020 ffff88006d9023a0 ffffffff81177b50=20
00000000000000db
[181321.375735] Call Trace:
[181321.376591]  [<ffffffff81177b50>] ? poll_freewait+0xe0/0xe0
[181321.377461]  [<ffffffff81177c40>] ? __pollwait+0xf0/0xf0
[181321.378325]  [<ffffffff81051970>] ? select_task_rq_fair+0x540/0xa60
[181321.379197]  [<ffffffff814158bf>] schedule+0x3f/0x60
[181321.380058]  [<ffffffffa072a705>]=20
wait_current_trans.isra.22+0xa5/0xf0 [btrfs]
[181321.380929]  [<ffffffff81086850>] ? abort_exclusive_wait+0xb0/0xb0
[181321.381802]  [<ffffffffa072be20>] start_transaction+0x1f0/0x2b0=20
[btrfs]
[181321.382684]  [<ffffffffa072bf35>] btrfs_join_transaction+0x15/0x20=20
[btrfs]
[181321.383561]  [<ffffffffa0736980>] btrfs_dirty_inode+0x50/0xd0=20
[btrfs]
[181321.384434]  [<ffffffffa0736c86>] btrfs_update_time+0xd6/0x170=20
[btrfs]
[181321.385311]  [<ffffffffa073aee8>] btrfs_file_aio_write+0x1c8/0x520=20
[btrfs]
[181321.386179]  [<ffffffff8116e8f2>] ? pipe_read+0x2d2/0x4e0
[181321.387043]  [<ffffffff81164302>] do_sync_write+0xd2/0x110
[181321.387899]  [<ffffffff81051019>] ? finish_task_switch+0x49/0xd0
[181321.388763]  [<ffffffff811f266c>] ?=20
security_file_permission+0x2c/0xb0
[181321.389623]  [<ffffffff811648b1>] ? rw_verify_area+0x61/0xf0
[181321.390475]  [<ffffffff81164c0f>] vfs_write+0xaf/0x180
[181321.391324]  [<ffffffff81164f3a>] sys_write+0x4a/0x90
[181321.392163]  [<ffffffff814190c2>] system_call_fastpath+0x16/0x1b
[181321.392993] INFO: task flush-btrfs-1:30940 blocked for more than=20
120 seconds.
[181321.393826] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[181321.394670] flush-btrfs-1   D 00000001033b5a85     0 30940      2=20
0x00000000
[181321.395531]  ffff8800236218d0 0000000000000046 ffff880000000000=20
ffffffffa075460e
[181321.396394]  ffff88007222b1e0 ffff880023621fd8 ffff880023621fd8=20
ffff880023621fd8
[181321.397258]  ffff880073e97200 ffff88007222b1e0 ffff88000dad1550=20
ffff880023621870
[181321.398118] Call Trace:
[181321.398977]  [<ffffffffa075460e>] ? btrfs_queue_worker+0x1ee/0x300=20
[btrfs]
[181321.399856]  [<ffffffffa07330b5>] ? run_delalloc_range+0x185/0x360=20
[btrfs]
[181321.400728]  [<ffffffff8101d639>] ? read_tsc+0x9/0x20
[181321.401593]  [<ffffffff81103140>] ? __lock_page+0x70/0x70
[181321.402460]  [<ffffffff814158bf>] schedule+0x3f/0x60
[181321.403310]  [<ffffffff8141596f>] io_schedule+0x8f/0xd0
[181321.404153]  [<ffffffff8110314e>] sleep_on_page+0xe/0x20
[181321.404988]  [<ffffffff8141623a>] __wait_on_bit_lock+0x5a/0xc0
[181321.405829]  [<ffffffff81103137>] __lock_page+0x67/0x70
[181321.406660]  [<ffffffff81086890>] ?=20
autoremove_wake_function+0x40/0x40
[181321.407500]  [<ffffffffa074a4d5>]=20
extent_write_cache_pages.isra.22.constprop.30+0x215/0x3f0 [btrfs]
[181321.408359]  [<ffffffffa074a8f5>] extent_writepages+0x45/0x60=20
[btrfs]
[181321.409220]  [<ffffffffa072f780>] ?=20
uncompress_inline.isra.47+0x1d0/0x1d0 [btrfs]
[181321.410085]  [<ffffffffa072ea68>] btrfs_writepages+0x28/0x30 [btrfs=
]
[181321.410946]  [<ffffffff8110eb64>] do_writepages+0x24/0x40
[181321.411799]  [<ffffffff8118ce0f>] writeback_single_inode+0x10f/0x3f=
0
[181321.412651]  [<ffffffff8118d4ea>] writeback_sb_inodes+0x1aa/0x270
[181321.413480]  [<ffffffff8118d64e>] __writeback_inodes_wb+0x9e/0xd0
[181321.414304]  [<ffffffff8118dc6b>] wb_writeback+0x37b/0x3b0
[181321.415118]  [<ffffffff8117ebd2>] ? get_nr_inodes+0x52/0x70
[181321.415934]  [<ffffffff8117f8d2>] ? get_nr_dirty_inodes+0x52/0x80
[181321.416731]  [<ffffffff8118dd3f>] wb_check_old_data_flush+0x9f/0xb0
[181321.417525]  [<ffffffff8118f21c>] wb_do_writeback+0x19c/0x230
[181321.418322]  [<ffffffff81415e43>] ? schedule_timeout+0x173/0x390
[181321.419127]  [<ffffffff81072c10>] ?=20
init_timer_deferrable_key+0x30/0x30
[181321.419928]  [<ffffffff8118f33c>] bdi_writeback_thread+0x8c/0x340
[181321.420724]  [<ffffffff8118f2b0>] ? wb_do_writeback+0x230/0x230
[181321.421513]  [<ffffffff81085f0c>] kthread+0x8c/0xa0
[181321.422300]  [<ffffffff8141b234>] kernel_thread_helper+0x4/0x10
[181321.423086]  [<ffffffff81085e80>] ? kthread_worker_fn+0x190/0x190
[181321.423868]  [<ffffffff8141b230>] ? gs_change+0x13/0x13
[181321.424650] INFO: task btrfs-delalloc-:30957 blocked for more than=20
120 seconds.
[181321.425455] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"=20
disables this message.
[181321.426264] btrfs-delalloc- D 00000001033b5a86     0 30957      2=20
0x00000000
[181321.427088]  ffff88005147fc50 0000000000000046 0080004000000000=20
0800040002000100
[181321.427922]  ffff880072ab8e40 ffff88005147ffd8 ffff88005147ffd8=20
ffff88005147ffd8
[181321.428764]  ffff880073f09c80 ffff880072ab8e40 0000000000000001=20
0000000000000000
[181321.429604] Call Trace:
[181321.430433]  [<ffffffffa06fea84>] ? zlib_tr_flush_block+0x5f4/0x6f0=
=20
[zlib_deflate]
[181321.431299]  [<ffffffffa06fb6cc>] ? flush_pending+0x4c/0x90=20
[zlib_deflate]
[181321.432176]  [<ffffffffa06fb6cc>] ? flush_pending+0x4c/0x90=20
[zlib_deflate]
[181321.433026]  [<ffffffffa06fc506>] ? zlib_deflate+0x1b6/0x410=20
[zlib_deflate]
[181321.433865]  [<ffffffff814158bf>] schedule+0x3f/0x60
[181321.434692]  [<ffffffffa072a705>]=20
wait_current_trans.isra.22+0xa5/0xf0 [btrfs]
[181321.435529]  [<ffffffff81086850>] ? abort_exclusive_wait+0xb0/0xb0
[181321.436362]  [<ffffffffa072be20>] start_transaction+0x1f0/0x2b0=20
[btrfs]
[181321.437204]  [<ffffffffa072bf35>] btrfs_join_transaction+0x15/0x20=20
[btrfs]
[181321.438039]  [<ffffffffa0733a55>] compress_file_range+0x2c5/0x660=20
[btrfs]
[181321.438876]  [<ffffffffa0733e25>] async_cow_start+0x35/0x50 [btrfs]
[181321.439707]  [<ffffffffa0754870>] worker_loop+0x150/0x520 [btrfs]
[181321.440535]  [<ffffffffa0754720>] ? btrfs_queue_worker+0x300/0x300=20
[btrfs]
[181321.441366]  [<ffffffff81085f0c>] kthread+0x8c/0xa0
[181321.442202]  [<ffffffff8141b234>] kernel_thread_helper+0x4/0x10
[181321.443039]  [<ffffffff81085e80>] ? kthread_worker_fn+0x190/0x190
[181321.443880]  [<ffffffff8141b230>] ? gs_change+0x13/0x13

Quoted 1 line · Chris M= ason

On Sat, Dec 03, 2011 at 04:36:44PM +0200, Konstantinos Skarlatos wrot=

Quoted 5 lines

Quoted 5 lines
unfortunately i was wrong. rc4 does not fix this issue for me when rsyncing large amounts of data...
my mount options:
mount -o loop,compress=3Dzlib,compress-force btrfs_test /storage/btr=

Quoted 3 lines

Quoted 1 line
the filesystem is a file on a raid5 xfs volume.
Oh, the loop + raid5 + xfs is going to cause problems. The loop driv=

Quoted 4 lines

is fine for testing but I wouldn't be using it in a production environment.
-chris

--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs" = in
the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html