Hiya, I got below those last night. That was 3 minutes after a bunch of rsync and ntfsclone processes started. It''s the first time it happens. I upgraded from 3.0rc6 to 3.0 yesterday. sysrq-t output attached. [30961.476020] INFO: task kthreadd:2 blocked for more than 120 seconds. [30961.482414] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [30961.490271] kthreadd D ffff880149526e20 0 2 0 0x00000000 [30961.497489] ffff880149526e20 0000000000000046 ffff88014fffb700 ffffea00007eb520 [30961.504977] ffff880147045890 0000000000012800 ffff88014952ffd8 ffff88014952ffd8 [30961.512525] 0000000000012800 ffff880149526e20 0000000000012800 0000000000012800 [30961.520179] Call Trace: [30961.522702] [<ffffffff8100e342>] ? read_tsc+0x5/0x14 [30961.527850] [<ffffffff81066feb>] ? timekeeping_get_ns+0xd/0x2a [30961.533861] [<ffffffff810b5c70>] ? lock_page+0x20/0x20 [30961.539134] [<ffffffff813354f3>] ? io_schedule+0x5b/0x75 [30961.548853] [<ffffffff810b5c79>] ? sleep_on_page+0x9/0x10 [30961.554424] [<ffffffff81335b74>] ? __wait_on_bit+0x3e/0x71 [30961.560042] [<ffffffff810b5e11>] ? wait_on_page_bit+0x6a/0x70 [30961.565912] [<ffffffff810600ad>] ? autoremove_wake_function+0x2a/0x2a [30961.572478] [<ffffffff810ef92d>] ? migrate_pages+0x1b6/0x39b [30961.578243] [<ffffffff810e851b>] ? suitable_migration_target+0x35/0x35 [30961.584877] [<ffffffff810e8ee2>] ? compact_zone+0x68e/0x6a1 [30961.590567] [<ffffffff8110b5f1>] ? shrink_dcache_memory+0x132/0x15d [30961.596934] [<ffffffff810e9075>] ? compact_zone_order+0x9e/0xab [30961.602954] [<ffffffff810e9112>] ? try_to_compact_pages+0x90/0xe6 [30961.609147] [<ffffffff810bc393>] ? __alloc_pages_direct_compact+0xac/0x163 [30961.616124] [<ffffffff810bc8cf>] ? __alloc_pages_nodemask+0x485/0x75c [30961.622665] [<ffffffff81044a50>] ? copy_process+0x109/0x10eb [30961.628462] [<ffffffff8103b012>] ? perf_event_task_sched_out+0x48/0x54 [30961.635108] [<ffffffff81045b60>] ? do_fork+0xff/0x263 [30961.640262] [<ffffffff8100f1e0>] ? kernel_thread+0x7b/0x83 [30961.645846] [<ffffffff8105fb91>] ? kthread_worker_fn+0x149/0x149 [30961.651955] [<ffffffff8133cba0>] ? gs_change+0x13/0x13 [30961.657193] [<ffffffff8105ff3e>] ? kthreadd+0xe7/0x125 [30961.662434] [<ffffffff8103b0a2>] ? finish_task_switch+0x84/0xaf [30961.668477] [<ffffffff8133cba4>] ? kernel_thread_helper+0x4/0x10 [30961.674587] [<ffffffff8105fe57>] ? tsk_fork_get_node+0x1a/0x1a [30961.680518] [<ffffffff8133cba0>] ? gs_change+0x13/0x13 [30961.685772] INFO: task btrfs-delayed-m:785 blocked for more than 120 seconds. [30961.692919] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [30961.700793] btrfs-delayed-m D ffff88014628a300 0 785 2 0x00000000 [30961.707874] ffff88014628a300 0000000000000046 ffff88014549cc28 000000000000eb3f [30961.715347] ffff880147044ab0 0000000000012800 ffff8801484c3fd8 ffff8801484c3fd8 [30961.722816] 0000000000012800 ffff88014628a300 0000000000012800 0000000000012800 [30961.730283] Call Trace: [30961.732750] [<ffffffff813367ec>] ? _raw_spin_lock_irqsave+0x9/0x25 [30961.739056] [<ffffffffa02bb89c>] ? btrfs_tree_lock+0x9a/0xa7 [btrfs] [30961.745524] [<ffffffffa02bb754>] ? btrfs_spin_on_block+0x49/0x49 [btrfs] [30961.752337] [<ffffffffa027a16d>] ? btrfs_lock_root_node+0x1d/0x3f [btrfs] [30961.759231] [<ffffffffa027d7a1>] ? btrfs_search_slot+0xe6/0x4d6 [btrfs] [30961.765948] [<ffffffff81335ce4>] ? mutex_lock+0xd/0x2d [30961.771190] [<ffffffff8103840a>] ? should_resched+0x5/0x24 [30961.776809] [<ffffffffa028c82a>] ? btrfs_lookup_inode+0x25/0x87 [btrfs] [30961.783527] [<ffffffff810383fc>] ? need_resched+0x1a/0x23 [30961.789062] [<ffffffff8103840a>] ? should_resched+0x5/0x24 [30961.794654] [<ffffffff8133565f>] ? _cond_resched+0x9/0x20 [30961.800155] [<ffffffff81335ce4>] ? mutex_lock+0xd/0x2d [30961.805412] [<ffffffffa02cd6c3>] ? btrfs_update_delayed_inode+0x6b/0x126 [btrfs] [30961.812967] [<ffffffffa02ce2a0>] ? btrfs_async_run_delayed_node_done+0x9f/0x1cb [btrfs] [30961.821126] [<ffffffffa02b6f8a>] ? worker_loop+0x17e/0x498 [btrfs] [30961.827420] [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs] [30961.834320] [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs] [30961.841209] [<ffffffff8105fc0b>] ? kthread+0x7a/0x82 [30961.846276] [<ffffffff8133cba4>] ? kernel_thread_helper+0x4/0x10 [30961.852381] [<ffffffff8105fb91>] ? kthread_worker_fn+0x149/0x149 [30961.858487] [<ffffffff8133cba0>] ? gs_change+0x13/0x13 [30961.863725] INFO: task btrfs-transacti:892 blocked for more than 120 seconds. [30961.870870] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [30961.878727] btrfs-transacti D ffff880147e24ee0 0 892 2 0x00000000 [30961.885811] ffff880147e24ee0 0000000000000046 ffffea000006f318 ffff880000000000 [30961.893280] ffff8801495660c0 0000000000012800 ffff880144357fd8 ffff880144357fd8 [30961.900743] 0000000000012800 ffff880147e24ee0 0000000000012800 0000000000012800 [30961.908210] Call Trace: [30961.910669] [<ffffffff8100e342>] ? read_tsc+0x5/0x14 [30961.915737] [<ffffffff810b5c70>] ? lock_page+0x20/0x20 [30961.920978] [<ffffffff813354f3>] ? io_schedule+0x5b/0x75 [30961.926390] [<ffffffff810b5c79>] ? sleep_on_page+0x9/0x10 [30961.931888] [<ffffffff81335b74>] ? __wait_on_bit+0x3e/0x71 [30961.937473] [<ffffffff810b5e11>] ? wait_on_page_bit+0x6a/0x70 [30961.943320] [<ffffffff810600ad>] ? autoremove_wake_function+0x2a/0x2a [30961.949871] [<ffffffffa02ac5f5>] ? lock_page+0x11/0x20 [btrfs] [30961.955817] [<ffffffffa02af4e3>] ? extent_write_cache_pages.clone.10.clone.17+0xed/0x21f [btrfs] [30961.964730] [<ffffffff810be856>] ? pagevec_lookup_tag+0x18/0x1f [30961.970757] [<ffffffff810b6468>] ? filemap_fdatawait_range+0x12c/0x14a [30961.977400] [<ffffffffa02af864>] ? extent_writepages+0x44/0x5a [btrfs] [30961.984042] [<ffffffffa0296e09>] ? uncompress_inline.clone.32+0x117/0x117 [btrfs] [30961.991639] [<ffffffff810b6729>] ? __filemap_fdatawrite_range+0x4b/0x50 [30961.998365] [<ffffffffa02abd38>] ? btrfs_wait_ordered_range+0x53/0x11e [btrfs] [30962.005706] [<ffffffff810383fc>] ? need_resched+0x1a/0x23 [30962.011202] [<ffffffff8103840a>] ? should_resched+0x5/0x24 [30962.016799] [<ffffffffa02abf30>] ? btrfs_run_ordered_operations+0x12d/0x1b6 [btrfs] [30962.024584] [<ffffffffa029354b>] ? btrfs_commit_transaction+0x22e/0x6fd [btrfs] [30962.032011] [<ffffffff810ece49>] ? kmem_cache_alloc+0x86/0xf0 [30962.037867] [<ffffffffa0292c7b>] ? join_transaction.clone.23+0xbb/0x1fc [btrfs] [30962.045293] [<ffffffff81060083>] ? wake_up_bit+0x23/0x23 [30962.050705] [<ffffffff810383fc>] ? need_resched+0x1a/0x23 [30962.056202] [<ffffffff8103840a>] ? should_resched+0x5/0x24 [30962.061800] [<ffffffffa028ddd7>] ? transaction_kthread+0x171/0x229 [btrfs] [30962.068785] [<ffffffffa028dc66>] ? btrfs_congested_fn+0x7b/0x7b [btrfs] [30962.075508] [<ffffffffa028dc66>] ? btrfs_congested_fn+0x7b/0x7b [btrfs] [30962.082223] [<ffffffff8105fc0b>] ? kthread+0x7a/0x82 [30962.087288] [<ffffffff8133cba4>] ? kernel_thread_helper+0x4/0x10 [30962.093393] [<ffffffff8105fb91>] ? kthread_worker_fn+0x149/0x149 [30962.099501] [<ffffffff8133cba0>] ? gs_change+0x13/0x13 [30962.104755] INFO: task btrfs-delalloc-:2380 blocked for more than 120 seconds. [30962.112007] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [30962.119860] btrfs-delalloc- D ffff880143f9a340 0 2380 2 0x00000000 [30962.126941] ffff880143f9a340 0000000000000046 ffff88014fffbe00 ffffffff00000000 [30962.134410] ffffffff8160b020 0000000000012800 ffff880111f49fd8 ffff880111f49fd8 [30962.141876] 0000000000012800 ffff880143f9a340 0000000000012800 0000000000012800 [30962.149344] Call Trace: [30962.151803] [<ffffffff81335939>] ? schedule_timeout+0x2d/0xd7 [30962.157651] [<ffffffff8100e28d>] ? paravirt_read_tsc+0x5/0x8 [30962.163411] [<ffffffff8100e74a>] ? native_sched_clock+0x28/0x30 [30962.169430] [<ffffffff8100e757>] ? sched_clock+0x5/0x8 [30962.174669] [<ffffffff81335713>] ? wait_for_common+0x9d/0x116 [30962.180518] [<ffffffff8103f0a4>] ? try_to_wake_up+0x199/0x199 [30962.186365] [<ffffffff8105fdb6>] ? kthread_create_on_node+0x8f/0x10a [30962.192825] [<ffffffffa02827be>] ? btrfs_put_block_group+0x73/0x73 [btrfs] [30962.199802] [<ffffffff810eccd8>] ? __kmalloc+0xde/0xf0 [30962.205040] [<ffffffff810383fc>] ? need_resched+0x1a/0x23 [30962.210555] [<ffffffffa028271a>] ? cache_block_group+0x1f3/0x224 [btrfs] [30962.217367] [<ffffffffa028620b>] ? find_free_extent.clone.64+0x41a/0x932 [btrfs] [30962.224890] [<ffffffffa02b0a14>] ? map_extent_buffer+0x6a/0xa1 [btrfs] [30962.231525] [<ffffffffa0287006>] ? btrfs_reserve_extent+0xb0/0x18e [btrfs] [30962.238512] [<ffffffffa028767a>] ? btrfs_alloc_free_block+0x219/0x33f [btrfs] [30962.245769] [<ffffffffa027d24c>] ? split_leaf+0x2c6/0x523 [btrfs] [30962.251969] [<ffffffffa027dad6>] ? btrfs_search_slot+0x41b/0x4d6 [btrfs] [30962.258777] [<ffffffffa027ea43>] ? btrfs_insert_empty_items+0x62/0xb3 [btrfs] [30962.266041] [<ffffffffa0298da3>] ? insert_inline_extent+0xa5/0x231 [btrfs] [30962.273029] [<ffffffffa0299056>] ? cow_file_range_inline+0x127/0x166 [btrfs] [30962.280189] [<ffffffffa029a431>] ? compress_file_range+0x326/0x55a [btrfs] [30962.287176] [<ffffffffa029a693>] ? async_cow_start+0x2e/0x43 [btrfs] [30962.293644] [<ffffffffa02b6f8a>] ? worker_loop+0x17e/0x498 [btrfs] [30962.299934] [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs] [30962.306831] [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs] [30962.313721] [<ffffffff8105fc0b>] ? kthread+0x7a/0x82 [30962.318787] [<ffffffff8133cba4>] ? kernel_thread_helper+0x4/0x10 [30962.324893] [<ffffffff8105fb91>] ? kthread_worker_fn+0x149/0x149 [30962.330999] [<ffffffff8133cba0>] ? gs_change+0x13/0x13 [30962.336256] INFO: task btrfs-endio-wri:2442 blocked for more than 120 seconds. [30962.343504] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [30962.351361] btrfs-endio-wri D ffff88013ee4d550 0 2442 2 0x00000000 [30962.358445] ffff88013ee4d550 0000000000000046 ffff880028ef7b20 ffff880100e3ce20 [30962.365911] ffff88003a95ea70 0000000000012800 ffff880028ef7fd8 ffff880028ef7fd8 [30962.373377] 0000000000012800 ffff88013ee4d550 0000000000012800 0000000000012800 [30962.380845] Call Trace: [30962.383301] [<ffffffff813367ec>] ? _raw_spin_lock_irqsave+0x9/0x25 [30962.389595] [<ffffffffa02bb89c>] ? btrfs_tree_lock+0x9a/0xa7 [btrfs] [30962.396063] [<ffffffffa02bb754>] ? btrfs_spin_on_block+0x49/0x49 [btrfs] [30962.402871] [<ffffffffa0279edb>] ? btrfs_set_path_blocking+0x21/0x32 [btrfs] [30962.410027] [<ffffffffa027da81>] ? btrfs_search_slot+0x3c6/0x4d6 [btrfs] [30962.416840] [<ffffffffa028b5fb>] ? btrfs_lookup_file_extent+0x34/0x39 [btrfs] [30962.424103] [<ffffffffa02a03c1>] ? btrfs_drop_extents+0xe4/0x6eb [btrfs] [30962.430904] [<ffffffff810bd65d>] ? __set_page_dirty_nobuffers+0x16/0xd6 [30962.437619] [<ffffffff810ed076>] ? kmem_cache_free+0x2d/0x69 [30962.443389] [<ffffffffa0297beb>] ? insert_reserved_file_extent.clone.34+0x66/0x215 [btrfs] [30962.451777] [<ffffffffa0293e52>] ? start_transaction+0x1ec/0x227 [btrfs] [30962.458585] [<ffffffff810383fc>] ? need_resched+0x1a/0x23 [30962.464095] [<ffffffffa0298a41>] ? btrfs_finish_ordered_io+0x1b6/0x298 [btrfs] [30962.471433] [<ffffffff810be064>] ? test_clear_page_writeback+0xb8/0xcc [30962.478074] [<ffffffffa02ad4dd>] ? end_bio_extent_writepage+0xa2/0x152 [btrfs] [30962.489565] [<ffffffffa02b6f8a>] ? worker_loop+0x17e/0x498 [btrfs] [30962.495858] [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs] [30962.502755] [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs] [30962.509646] [<ffffffff8105fc0b>] ? kthread+0x7a/0x82 [30962.514710] [<ffffffff8133cba4>] ? kernel_thread_helper+0x4/0x10 [30962.520815] [<ffffffff8105fb91>] ? kthread_worker_fn+0x149/0x149 [30962.526921] [<ffffffff8133cba0>] ? gs_change+0x13/0x13 [30962.532177] INFO: task rsync:3139 blocked for more than 120 seconds. [30962.538543] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [30962.546402] rsync D ffff88013bb86040 0 3139 3040 0x00000000 [30962.553485] ffff88013bb86040 0000000000000082 0000000000000000 ffffffff00000000 [30962.560951] ffffffff8160b020 0000000000012800 ffff88010d093fd8 ffff88010d093fd8 [30962.568416] 0000000000012800 ffff88013bb86040 0000000000012800 0000000000012800 [30962.575876] Call Trace: [30962.578357] [<ffffffffa0292b91>] ? wait_current_trans.clone.22+0xa1/0xd0 [btrfs] [30962.585870] [<ffffffff81060083>] ? wake_up_bit+0x23/0x23 [30962.591292] [<ffffffffa0293d3f>] ? start_transaction+0xd9/0x227 [btrfs] [30962.598010] [<ffffffff810ed076>] ? kmem_cache_free+0x2d/0x69 [30962.603782] [<ffffffffa029dbb1>] ? btrfs_create+0x33/0x18d [btrfs] [30962.610062] [<ffffffff810eccd8>] ? __kmalloc+0xde/0xf0 [30962.615304] [<ffffffff811038d1>] ? generic_permission+0xe/0x9b [30962.621234] [<ffffffff811053d2>] ? vfs_create+0x66/0x88 [30962.626558] [<ffffffff81103bf2>] ? d_alloc_and_lookup+0x3a/0x60 [30962.632577] [<ffffffff81105636>] ? do_last+0x242/0x584 [30962.637814] [<ffffffff81106bea>] ? path_openat+0xc7/0x349 [30962.643313] [<ffffffff810fb5f1>] ? do_sync_read+0xb1/0xea [30962.648816] [<ffffffff8103840a>] ? should_resched+0x5/0x24 [30962.654400] [<ffffffff81106e98>] ? do_filp_open+0x2c/0x72 [30962.659898] [<ffffffff8133565f>] ? _cond_resched+0x9/0x20 [30962.665402] [<ffffffff811ac741>] ? __strncpy_from_user+0x19/0x4a [30962.671509] [<ffffffff81110208>] ? alloc_fd+0x69/0x110 [30962.676746] [<ffffffff810fb138>] ? do_sys_open+0x5f/0xe6 [30962.682160] [<ffffffff8133ba92>] ? system_call_fastpath+0x16/0x1b [30962.688355] INFO: task btrfs-delayed-m:3321 blocked for more than 120 seconds. [30962.695602] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [30962.703459] btrfs-delayed-m D ffff880147044ab0 0 3321 2 0x00000000 [30962.710549] ffff880147044ab0 0000000000000046 ffff88014549cc28 000000000000eb3f [30962.718016] ffff880143e6e340 0000000000012800 ffff88006c569fd8 ffff88006c569fd8 [30962.725482] 0000000000012800 ffff880147044ab0 0000000000012800 0000000000012800 [30962.732948] Call Trace: [30962.735405] [<ffffffff813367ec>] ? _raw_spin_lock_irqsave+0x9/0x25 [30962.741698] [<ffffffffa02bb89c>] ? btrfs_tree_lock+0x9a/0xa7 [btrfs] [30962.748167] [<ffffffffa02bb754>] ? btrfs_spin_on_block+0x49/0x49 [btrfs] [30962.754973] [<ffffffffa027a16d>] ? btrfs_lock_root_node+0x1d/0x3f [btrfs] [30962.761869] [<ffffffffa027d7a1>] ? btrfs_search_slot+0xe6/0x4d6 [btrfs] [30962.768584] [<ffffffff81335ce4>] ? mutex_lock+0xd/0x2d [30962.773822] [<ffffffff8103840a>] ? should_resched+0x5/0x24 [30962.779418] [<ffffffffa028c82a>] ? btrfs_lookup_inode+0x25/0x87 [btrfs] [30962.786133] [<ffffffff810383fc>] ? need_resched+0x1a/0x23 [30962.791631] [<ffffffff8103840a>] ? should_resched+0x5/0x24 [30962.797215] [<ffffffff8133565f>] ? _cond_resched+0x9/0x20 [30962.802716] [<ffffffff81335ce4>] ? mutex_lock+0xd/0x2d [30962.807965] [<ffffffffa02cd6c3>] ? btrfs_update_delayed_inode+0x6b/0x126 [btrfs] [30962.815485] [<ffffffffa02ce2a0>] ? btrfs_async_run_delayed_node_done+0x9f/0x1cb [btrfs] [30962.823616] [<ffffffffa02b6f8a>] ? worker_loop+0x17e/0x498 [btrfs] [30962.829907] [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs] [30962.836807] [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs] [30962.843694] [<ffffffff8105fc0b>] ? kthread+0x7a/0x82 [30962.848760] [<ffffffff8133cba4>] ? kernel_thread_helper+0x4/0x10 [30962.854868] [<ffffffff8105fb91>] ? kthread_worker_fn+0x149/0x149 [30962.860972] [<ffffffff8133cba0>] ? gs_change+0x13/0x13 [30962.866210] INFO: task ntfsclone:3437 blocked for more than 120 seconds. [30962.872923] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [30962.880777] ntfsclone D ffff8800b26250a0 0 3437 3399 0x00000000 [30962.887856] ffff8800b26250a0 0000000000000086 0000000000000296 ffffffff00000001 [30962.895323] ffff8801428e6ee0 0000000000012800 ffff88003d6a3fd8 ffff88003d6a3fd8 [30962.902789] 0000000000012800 ffff8800b26250a0 0000000000012800 0000000000012800 [30962.910256] Call Trace: [30962.912730] [<ffffffffa0292b91>] ? wait_current_trans.clone.22+0xa1/0xd0 [btrfs] [30962.920243] [<ffffffff81060083>] ? wake_up_bit+0x23/0x23 [30962.925668] [<ffffffffa029fb73>] ? __btrfs_buffered_write.clone.14+0x24b/0x29a [btrfs] [30962.933711] [<ffffffffa029ff5d>] ? btrfs_file_aio_write+0x39b/0x435 [btrfs] [30962.940775] [<ffffffff810fb507>] ? do_sync_write+0xb1/0xea [30962.946363] [<ffffffff811650d9>] ? security_file_permission+0x18/0x33 [30962.952907] [<ffffffff810fbb1e>] ? vfs_write+0xa6/0xf9 [30962.958147] [<ffffffff810fbd13>] ? sys_write+0x45/0x6b [30962.963384] [<ffffffff8133ba92>] ? system_call_fastpath+0x16/0x1b [30962.969577] INFO: task btrfs-delayed-m:3438 blocked for more than 120 seconds. [30962.976828] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [30962.984684] btrfs-delayed-m D ffff8801428e6ee0 0 3438 2 0x00000000 [30962.991762] ffff8801428e6ee0 0000000000000046 ffff8800299ebcf0 ffff88010df02c70 [30962.999229] ffff880101862ab0 0000000000012800 ffff8800299ebfd8 ffff8800299ebfd8 [30963.006695] 0000000000012800 ffff8801428e6ee0 0000000000012800 0000000000012800 [30963.014163] Call Trace: [30963.016625] [<ffffffff813367ec>] ? _raw_spin_lock_irqsave+0x9/0x25 [30963.022917] [<ffffffffa02bb89c>] ? btrfs_tree_lock+0x9a/0xa7 [btrfs] [30963.029384] [<ffffffffa02bb754>] ? btrfs_spin_on_block+0x49/0x49 [btrfs] [30963.036193] [<ffffffffa0279edb>] ? btrfs_set_path_blocking+0x21/0x32 [btrfs] [30963.043346] [<ffffffffa027da81>] ? btrfs_search_slot+0x3c6/0x4d6 [btrfs] [30963.050150] [<ffffffff8103840a>] ? should_resched+0x5/0x24 [30963.055746] [<ffffffffa028c82a>] ? btrfs_lookup_inode+0x25/0x87 [btrfs] [30963.062460] [<ffffffff810383fc>] ? need_resched+0x1a/0x23 [30963.067961] [<ffffffff8103840a>] ? should_resched+0x5/0x24 [30963.073547] [<ffffffff8133565f>] ? _cond_resched+0x9/0x20 [30963.079045] [<ffffffff81335ce4>] ? mutex_lock+0xd/0x2d [30963.084296] [<ffffffffa02cd6c3>] ? btrfs_update_delayed_inode+0x6b/0x126 [btrfs] [30963.091818] [<ffffffffa02ce2a0>] ? btrfs_async_run_delayed_node_done+0x9f/0x1cb [btrfs] [30963.099947] [<ffffffffa02b6f8a>] ? worker_loop+0x17e/0x498 [btrfs] [30963.106239] [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs] [30963.113138] [<ffffffffa02b6e0c>] ? btrfs_queue_worker+0x25c/0x25c [btrfs] [30963.120028] [<ffffffff8105fc0b>] ? kthread+0x7a/0x82 [30963.125093] [<ffffffff8133cba4>] ? kernel_thread_helper+0x4/0x10 [30963.131199] [<ffffffff8105fb91>] ? kthread_worker_fn+0x149/0x149 [30963.137308] [<ffffffff8133cba0>] ? gs_change+0x13/0x13 [30963.142544] INFO: task rsync:3439 blocked for more than 120 seconds. [30963.148908] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [30963.156765] rsync D ffff880114e02870 0 3439 3172 0x00000000 [30963.163843] ffff880114e02870 0000000000000082 00000000000c0fff ffff880114e02ef8 [30963.171307] ffff880146786040 0000000000012800 ffff8800d335bfd8 ffff8800d335bfd8 [30963.178775] 0000000000012800 ffff880114e02870 0000000000012800 0000000000012800 [30963.186240] Call Trace: [30963.188704] [<ffffffff813367ec>] ? _raw_spin_lock_irqsave+0x9/0x25 [30963.194994] [<ffffffffa0292b91>] ? wait_current_trans.clone.22+0xa1/0xd0 [btrfs] [30963.202511] [<ffffffff81060083>] ? wake_up_bit+0x23/0x23 [30963.207936] [<ffffffffa029fb73>] ? __btrfs_buffered_write.clone.14+0x24b/0x29a [btrfs] [30963.215979] [<ffffffffa029ff5d>] ? btrfs_file_aio_write+0x39b/0x435 [btrfs] [30963.223043] [<ffffffff811035df>] ? dget+0x12/0x1e [30963.227846] [<ffffffff8110ba59>] ? dput+0x29/0xea [30963.232651] [<ffffffff81111b05>] ? mntput_no_expire+0x21/0xd5 [30963.238499] [<ffffffff810fb507>] ? do_sync_write+0xb1/0xea [30963.244084] [<ffffffff811650d9>] ? security_file_permission+0x18/0x33 [30963.250621] [<ffffffff810fbb1e>] ? vfs_write+0xa6/0xf9 [30963.255860] [<ffffffff810fbd13>] ? sys_write+0x45/0x6b [30963.261097] [<ffffffff8133ba92>] ? system_call_fastpath+0x16/0x1b -- Stephane
2011-07-28 07:23:43 +0100, Stephane Chazelas:> Hiya, I got below those last night. That was 3 minutes after a > bunch of rsync and ntfsclone processes started. > > It''s the first time it happens. I upgraded from 3.0rc6 to 3.0 > yesterday.[...] And again this morning, though at that point only one ntfsclone process was actively writing to the FS. At this point, I can read directories and stat(2) files on that FS, but reading or writing files hangs. I''ll try and revert to 3.0rc6 to see if that makes a difference. call traces for some processes trying to read from the FS: cat D ffff8801424ee240 0 3478 1 0x00000005 ffff8801424ee240 0000000000000086 ffff8801080497e8 ffff8800494322e0 ffff8801461908b0 0000000000012800 ffff880108049fd8 ffff880108049fd8 0000000000012800 ffff8801424ee240 0000000000012800 0000000000012800 Call Trace: [<ffffffff813367ec>] ? _raw_spin_lock_irqsave+0x9/0x25 [<ffffffffa02d989c>] ? btrfs_tree_lock+0x9a/0xa7 [btrfs] [<ffffffffa02d9754>] ? btrfs_spin_on_block+0x49/0x49 [btrfs] [<ffffffffa0297edb>] ? btrfs_set_path_blocking+0x21/0x32 [btrfs] [<ffffffffa029ba81>] ? btrfs_search_slot+0x3c6/0x4d6 [btrfs] [<ffffffffa02a923a>] ? btrfs_lookup_csum+0x65/0x105 [btrfs] [<ffffffffa02c9bb2>] ? btrfs_lookup_ordered_extent+0x2b/0x69 [btrfs] [<ffffffffa02ca1fa>] ? btrfs_find_ordered_sum+0x34/0xcc [btrfs] [<ffffffffa02a9449>] ? __btrfs_lookup_bio_sums+0x16f/0x2ed [btrfs] [<ffffffffa02e3bb8>] ? btrfs_submit_compressed_read+0x3b7/0x42e [btrfs] [<ffffffffa02ca73b>] ? submit_one_bio+0x85/0xbc [btrfs] [<ffffffffa02cc880>] ? submit_extent_page.clone.16+0x118/0x1b9 [btrfs] [<ffffffffa02cc290>] ? check_page_uptodate+0x36/0x36 [btrfs] [<ffffffffa02ccda4>] ? __extent_read_full_page+0x463/0x4cc [btrfs] [<ffffffffa02cc290>] ? check_page_uptodate+0x36/0x36 [btrfs] [<ffffffffa02b4e09>] ? uncompress_inline.clone.32+0x117/0x117 [btrfs] [<ffffffffa02cd92b>] ? extent_readpages+0xb1/0xf6 [btrfs] [<ffffffffa02b4e09>] ? uncompress_inline.clone.32+0x117/0x117 [btrfs] [<ffffffff810be21b>] ? __do_page_cache_readahead+0x124/0x1c8 [<ffffffff810be526>] ? ra_submit+0x1c/0x23 [<ffffffff810b6e9e>] ? generic_file_aio_read+0x2a7/0x5c7 [<ffffffff810fb5f1>] ? do_sync_read+0xb1/0xea [<ffffffff81336815>] ? _raw_spin_lock_irq+0xd/0x1a [<ffffffff810fbc10>] ? vfs_read+0x9f/0xf2 [<ffffffff81012599>] ? syscall_trace_enter+0xb5/0x15d [<ffffffff810fbca8>] ? sys_read+0x45/0x6b [<ffffffff8133bca7>] ? tracesys+0xd9/0xde wc D ffff8801424ef710 0 3495 1 0x00000005 ffff8801424ef710 0000000000000086 ffffffff811ab802 ffff88014951f5c0 ffffffff8160b020 0000000000012800 ffff880109617fd8 ffff880109617fd8 0000000000012800 ffff8801424ef710 0000000000012800 0000000000012800 Call Trace: [<ffffffff811ab802>] ? delay_tsc+0x2b/0x68 [<ffffffff813367ec>] ? _raw_spin_lock_irqsave+0x9/0x25 [<ffffffffa02d989c>] ? btrfs_tree_lock+0x9a/0xa7 [btrfs] [<ffffffffa02d9754>] ? btrfs_spin_on_block+0x49/0x49 [btrfs] [<ffffffffa02ce989>] ? map_private_extent_buffer+0xa3/0xc4 [btrfs] [<ffffffffa029816d>] ? btrfs_lock_root_node+0x1d/0x3f [btrfs] [<ffffffffa029b7a1>] ? btrfs_search_slot+0xe6/0x4d6 [btrfs] [<ffffffffa02ac5a1>] ? btrfs_header_generation.clone.17+0xf/0x14 [btrfs] [<ffffffffa02a923a>] ? btrfs_lookup_csum+0x65/0x105 [btrfs] [<ffffffffa02c9bb2>] ? btrfs_lookup_ordered_extent+0x2b/0x69 [btrfs] [<ffffffffa02ca1fa>] ? btrfs_find_ordered_sum+0x34/0xcc [btrfs] [<ffffffffa02a9449>] ? __btrfs_lookup_bio_sums+0x16f/0x2ed [btrfs] [<ffffffffa02b3226>] ? btrfs_submit_bio_hook+0xa4/0x129 [btrfs] [<ffffffffa02ca73b>] ? submit_one_bio+0x85/0xbc [btrfs] [<ffffffffa02cc880>] ? submit_extent_page.clone.16+0x118/0x1b9 [btrfs] [<ffffffffa02cc290>] ? check_page_uptodate+0x36/0x36 [btrfs] [<ffffffffa02ccda4>] ? __extent_read_full_page+0x463/0x4cc [btrfs] [<ffffffffa02cc290>] ? check_page_uptodate+0x36/0x36 [btrfs] [<ffffffffa02b4e09>] ? uncompress_inline.clone.32+0x117/0x117 [btrfs] [<ffffffffa02cd92b>] ? extent_readpages+0xb1/0xf6 [btrfs] [<ffffffffa02b4e09>] ? uncompress_inline.clone.32+0x117/0x117 [btrfs] [<ffffffff810be21b>] ? __do_page_cache_readahead+0x124/0x1c8 [<ffffffff810be526>] ? ra_submit+0x1c/0x23 [<ffffffff810b6e62>] ? generic_file_aio_read+0x26b/0x5c7 [<ffffffff810fb5f1>] ? do_sync_read+0xb1/0xea [<ffffffff81336815>] ? _raw_spin_lock_irq+0xd/0x1a [<ffffffff810fbc10>] ? vfs_read+0x9f/0xf2 [<ffffffff81012599>] ? syscall_trace_enter+0xb5/0x15d [<ffffffff810fbca8>] ? sys_read+0x45/0x6b [<ffffffff8133bca7>] ? tracesys+0xd9/0xde tail D ffff88014651b750 0 3442 1844 0x00000004 ffff88014651b750 0000000000000082 ffff880147b06508 ffffffff00000000 ffff8801495660c0 0000000000012800 ffff88010e05dfd8 ffff88010e05dfd8 0000000000012800 ffff88014651b750 0000000000012800 0000000000012800 Call Trace: [<ffffffff81335e18>] ? __mutex_lock_common.clone.5+0x114/0x179 [<ffffffff81335cf1>] ? mutex_lock+0x1a/0x2d [<ffffffff810fb6d8>] ? generic_file_llseek+0x21/0x52 [<ffffffff810fb745>] ? sys_lseek+0x3c/0x59 [<ffffffff8133ba92>] ? system_call_fastpath+0x16/0x1b rm D ffff8801424bd060 0 3504 1 0x00000005 ffff8801424bd060 0000000000000086 0000000000000000 0000000000000001 ffff8801495660c0 0000000000012800 ffff880118b21fd8 ffff880118b21fd8 0000000000012800 ffff8801424bd060 0000000000012800 0000000000012800 Call Trace: [<ffffffff813367ec>] ? _raw_spin_lock_irqsave+0x9/0x25 [<ffffffffa02b0b91>] ? wait_current_trans.clone.22+0xa1/0xd0 [btrfs] [<ffffffff81060083>] ? wake_up_bit+0x23/0x23 [<ffffffffa02b1d3f>] ? start_transaction+0xd9/0x227 [btrfs] [<ffffffffa02b2a3d>] ? __unlink_start_trans+0x52/0x399 [btrfs] [<ffffffff8103840a>] ? should_resched+0x5/0x24 [<ffffffff8133565f>] ? _cond_resched+0x9/0x20 [<ffffffff811038d1>] ? generic_permission+0xe/0x9b [<ffffffffa02b898f>] ? btrfs_unlink+0x1e/0xa4 [btrfs] [<ffffffff81104706>] ? vfs_unlink+0x65/0xbe [<ffffffff811068e3>] ? do_unlinkat+0xc6/0x14d [<ffffffff81011968>] ? ptrace_report_syscall.clone.8+0x27/0x4f [<ffffffff81012599>] ? syscall_trace_enter+0xb5/0x15d [<ffffffff8133bca7>] ? tracesys+0xd9/0xde tee D ffff88013d9d4140 0 3506 1 0x00000005 ffff88013d9d4140 0000000000000082 ffff880142634c40 ffff880142634730 ffffffff8160b020 0000000000012800 ffff88007e18bfd8 ffff88007e18bfd8 0000000000012800 ffff88013d9d4140 0000000000012800 0000000000012800 Call Trace: [<ffffffff8103b012>] ? perf_event_task_sched_out+0x48/0x54 [<ffffffff81335e18>] ? __mutex_lock_common.clone.5+0x114/0x179 [<ffffffff81103865>] ? exec_permission+0x1f/0x7d [<ffffffff81335cf1>] ? mutex_lock+0x1a/0x2d [<ffffffff8110558f>] ? do_last+0x19b/0x584 [<ffffffff81106bea>] ? path_openat+0xc7/0x349 [<ffffffff81336815>] ? _raw_spin_lock_irq+0xd/0x1a [<ffffffff81106e98>] ? do_filp_open+0x2c/0x72 [<ffffffff8133565f>] ? _cond_resched+0x9/0x20 [<ffffffff811ac741>] ? __strncpy_from_user+0x19/0x4a [<ffffffff81110208>] ? alloc_fd+0x69/0x110 [<ffffffff810fb138>] ? do_sys_open+0x5f/0xe6 [<ffffffff8133bca7>] ? tracesys+0xd9/0xde ntfsclone D ffff88013e4fd160 0 2757 2601 0x00000004 ffff88013e4fd160 0000000000000082 ffff88013f390710 ffffffff81023145 ffff8801495660c0 0000000000012800 ffff8801094f1fd8 ffff8801094f1fd8 0000000000012800 ffff88013e4fd160 0000000000012800 0000000000012800 Call Trace: [<ffffffff81023145>] ? _flat_send_IPI_mask+0x6a/0x7c [<ffffffff8100e342>] ? read_tsc+0x5/0x14 [<ffffffff81066feb>] ? timekeeping_get_ns+0xd/0x2a [<ffffffff810b5c70>] ? lock_page+0x20/0x20 [<ffffffff813354f3>] ? io_schedule+0x5b/0x75 [<ffffffff810b5c79>] ? sleep_on_page+0x9/0x10 [<ffffffff81335b74>] ? __wait_on_bit+0x3e/0x71 [<ffffffff8103840a>] ? should_resched+0x5/0x24 [<ffffffff8133565f>] ? _cond_resched+0x9/0x20 [<ffffffff810b5e11>] ? wait_on_page_bit+0x6a/0x70 [<ffffffff810600ad>] ? autoremove_wake_function+0x2a/0x2a [<ffffffffa02bd29e>] ? prepare_pages.clone.12+0x15b/0x2fd [btrfs] [<ffffffffa02bda5a>] ? __btrfs_buffered_write.clone.14+0x132/0x29a [btrfs] [<ffffffff81117b72>] ? inode_to_bdi+0x20/0x42 [<ffffffffa02bdf5d>] ? btrfs_file_aio_write+0x39b/0x435 [btrfs] [<ffffffff810fb507>] ? do_sync_write+0xb1/0xea [<ffffffff81126459>] ? fsnotify+0x23d/0x24f [<ffffffff811650d9>] ? security_file_permission+0x18/0x33 [<ffffffff810fbb1e>] ? vfs_write+0xa6/0xf9 [<ffffffff810fbd13>] ? sys_write+0x45/0x6b [<ffffffff8133ba92>] ? system_call_fastpath+0x16/0x1b Best regards, Stephane -- To unsubscribe from this list: send the line "unsubscribe linux-btrfs" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On Thu, 28 Jul 2011 04:23:43 PM Stephane Chazelas wrote:> Hiya, I got below those last night. That was 3 minutes after a > bunch of rsync and ntfsclone processes started.Similar here with an rsync to an external USB drive (SATA) from a local ext4 partition. This is with the Ubuntu mainline PPA (AMD64) build of 3.0. http://kernel.ubuntu.com/~kernel-ppa/mainline/v3.0-oneiric/linux-image-3.0.0-0300- generic_3.0.0-0300.201107220917_amd64.deb [175681.180099] INFO: task flush-btrfs-1:26899 blocked for more than 120 seconds. [175681.180104] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [175681.180106] flush-btrfs-1 D ffff88021e64df80 0 26899 2 0x00000000 [175681.180111] ffff880152e597d0 0000000000000046 ffff880152e596d0 ffff880152e59fd8 [175681.180115] ffff880152e597d0 0000000000012a40 0000000000012a40 ffff880152e59fd8 [175681.180119] ffff880152e59fd8 0000000000012a40 ffff88021e64dbc0 ffff880222d28000 [175681.180124] Call Trace: [175681.180132] [<ffffffff812e90de>] ? radix_tree_gang_lookup_slot+0x7e/0xc0 [175681.180160] [<ffffffffa0263394>] ? clear_extent_bit+0x194/0x380 [btrfs] [175681.180166] [<ffffffff8110e129>] ? find_get_pages_contig+0x39/0xe0 [175681.180171] [<ffffffff81034f69>] ? default_spin_lock_flags+0x9/0x10 [175681.180175] [<ffffffff815dfd84>] ? _raw_spin_lock_irqsave+0x34/0x50 [175681.180179] [<ffffffff81084efc>] ? prepare_to_wait+0x7c/0x90 [175681.180192] [<ffffffffa02430c9>] wait_current_trans+0x99/0x100 [btrfs] [175681.180195] [<ffffffff81084c40>] ? wake_up_bit+0x40/0x40 [175681.180198] [<ffffffff815dfd3e>] ? _raw_spin_lock+0xe/0x20 [175681.180210] [<ffffffffa0244ef8>] start_transaction+0x138/0x270 [btrfs] [175681.180223] [<ffffffffa0245085>] btrfs_join_transaction+0x15/0x20 [btrfs] [175681.180236] [<ffffffffa024a952>] cow_file_range+0x82/0x390 [btrfs] [175681.180239] [<ffffffff815dfd3e>] ? _raw_spin_lock+0xe/0x20 [175681.180252] [<ffffffffa0264228>] ? test_range_bit+0x88/0x140 [btrfs] [175681.180266] [<ffffffffa024c6af>] run_delalloc_range+0x4f/0x80 [btrfs] [175681.180279] [<ffffffffa0266ac1>] __extent_writepage+0x4b1/0x650 [btrfs] [175681.180283] [<ffffffff812e9a40>] ? radix_tree_gang_lookup_tag_slot+0x90/0xd0 [175681.180287] [<ffffffff8110d125>] ? find_get_pages_tag+0x45/0x100 [175681.180300] [<ffffffffa0266138>] extent_write_cache_pages+0x208/0x2d0 [btrfs] [175681.180314] [<ffffffffa0262720>] ? flush_epd_write_bio+0x50/0x50 [btrfs] [175681.180327] [<ffffffffa0266610>] ? find_lock_delalloc_range+0x1d0/0x1d0 [btrfs] [175681.180342] [<ffffffffa0266254>] extent_writepages+0x54/0x70 [btrfs] [175681.180355] [<ffffffffa0250520>] ? btrfs_page_mkwrite+0x2d0/0x2d0 [btrfs] [175681.180369] [<ffffffffa0246f18>] btrfs_writepages+0x28/0x30 [btrfs] [175681.180372] [<ffffffff81117c51>] do_writepages+0x21/0x40 [175681.180376] [<ffffffff81191514>] writeback_single_inode+0xf4/0x210 [175681.180380] [<ffffffff8105844e>] ? put_prev_entity+0x2e/0x70 [175681.180383] [<ffffffff811918e0>] writeback_sb_inodes+0xe0/0x190 [175681.180386] [<ffffffff81191aff>] writeback_inodes_wb+0xcf/0xf0 [175681.180389] [<ffffffff81191d63>] wb_writeback+0x243/0x370 [175681.180393] [<ffffffff8107184b>] ? lock_timer_base+0x3b/0x70 [175681.180396] [<ffffffff81191f19>] wb_check_old_data_flush+0x89/0xa0 [175681.180398] [<ffffffff8119204b>] wb_do_writeback+0x8b/0xe0 [175681.180401] [<ffffffff811920a0>] ? wb_do_writeback+0xe0/0xe0 [175681.180404] [<ffffffff81192153>] bdi_writeback_thread+0xb3/0x260 [175681.180406] [<ffffffff811920a0>] ? wb_do_writeback+0xe0/0xe0 [175681.180409] [<ffffffff81084577>] kthread+0x97/0xa0 [175681.180413] [<ffffffff815e94a4>] kernel_thread_helper+0x4/0x10 [175681.180416] [<ffffffff810844e0>] ? kthread_bind+0x80/0x80 [175681.180419] [<ffffffff815e94a0>] ? gs_change+0x13/0x13 -- Chris Samuel : http://www.csamuel.org/ : Melbourne, VIC This email may come with a PGP signature as a file. Do not panic. For more info see: http://en.wikipedia.org/wiki/OpenPGP
On Thu, Jul 28, 2011 at 07:23:43AM +0100, Stephane Chazelas wrote:> Hiya, I got below those last night. That was 3 minutes after a > bunch of rsync and ntfsclone processes started. > > It''s the first time it happens. I upgraded from 3.0rc6 to 3.0 > yesterday. >Ok I fixed that recently and Chris just sent it to Linus. The patch you are looking for is Btrfs: use a worker thread to do caching Thanks, Josef -- To unsubscribe from this list: send the line "unsubscribe linux-btrfs" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
2011-07-28 10:22:54 -0400, Josef Bacik:> On Thu, Jul 28, 2011 at 07:23:43AM +0100, Stephane Chazelas wrote: > > Hiya, I got below those last night. That was 3 minutes after a > > bunch of rsync and ntfsclone processes started. > > > > It''s the first time it happens. I upgraded from 3.0rc6 to 3.0 > > yesterday. > > > > Ok I fixed that recently and Chris just sent it to Linus. The patch you are > looking for is > > Btrfs: use a worker thread to do caching[...] Thanks a lot Josef, That seems to have done the trick. I''ve not reproduced the issue yet with that patch applied. Strange that I only get the issue with 3.0 and not 3.0rc6 though.... -- Stephane -- To unsubscribe from this list: send the line "unsubscribe linux-btrfs" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On 07/29/2011 08:29 AM, Stephane Chazelas wrote:> 2011-07-28 10:22:54 -0400, Josef Bacik: >> On Thu, Jul 28, 2011 at 07:23:43AM +0100, Stephane Chazelas wrote: >>> Hiya, I got below those last night. That was 3 minutes after a >>> bunch of rsync and ntfsclone processes started. >>> >>> It''s the first time it happens. I upgraded from 3.0rc6 to 3.0 >>> yesterday. >>> >> >> Ok I fixed that recently and Chris just sent it to Linus. The patch you are >> looking for is >> >> Btrfs: use a worker thread to do caching > [...] > > Thanks a lot Josef, > > That seems to have done the trick. I''ve not reproduced the issue > yet with that patch applied. Strange that I only get the issue > with 3.0 and not 3.0rc6 though.... >Just bad luck really. Thanks, Josef -- To unsubscribe from this list: send the line "unsubscribe linux-btrfs" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html