On Thu, Jul 12, 2018 at 11:40:54AM +0100, Filipe Manana wrote:
>On Wed, Jul 11, 2018 at 10:02 AM, Lu Fengqi <lufq.f...@cn.fujitsu.com> wrote:
>> Hi,
>>
>> When I run generic/041 with v4.18-rc3 (turn on kasan and hung task
>> detection), btrfs-transaction kthread will trigger the hung task timeout
>> (stall at wait_event in btrfs_commit_transaction). At the same time, you
>> can see that xfs_io -c fsync will occupy 100% of the CPU. I am not sure
>> whether this is a problem. Any suggestion?
>
>Well, something at 100% cpu and that seems hang forever is definitely
>a problem, specially a workload as simple as the one in generic/041
To clarify, the hung task will end within 500s. Without KASAN, it will
end within 80s, so it won't trigger hung task timeout 120s. I'm not sure
if this is just slow, or have some problem?
>(never happened to me, even on vanilla 4.18-rc4).
>Do you have the stack trace for the fsync task? What you pasted below
I will send the stack trace tomorrow.
--
Thanks,
Lu
>is only for the transaction kthread and that alone doesn't help.
>
>>
>> [Wed Jul 11 15:50:08 2018] INFO: task btrfs-transacti:1053 blocked for more
>> than 120 seconds.
>> [Wed Jul 11 15:50:08 2018] Not tainted 4.18.0-rc3-custom #14
>> [Wed Jul 11 15:50:08 2018] "echo 0 >
>> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
>> [Wed Jul 11 15:50:08 2018] btrfs-transacti D 0 1053 2 0x80000000
>> [Wed Jul 11 15:50:08 2018] Call Trace:
>> [Wed Jul 11 15:50:08 2018] ? __schedule+0x5b2/0x1380
>> [Wed Jul 11 15:50:08 2018] ? check_flags.part.23+0x240/0x240
>> [Wed Jul 11 15:50:08 2018] ? firmware_map_remove+0x187/0x187
>> [Wed Jul 11 15:50:08 2018] ? ___preempt_schedule+0x16/0x18
>> [Wed Jul 11 15:50:08 2018] ? mark_held_locks+0x6e/0x90
>> [Wed Jul 11 15:50:08 2018] ? _raw_spin_unlock_irqrestore+0x59/0x70
>> [Wed Jul 11 15:50:08 2018] ? preempt_count_sub+0x14/0xc0
>> [Wed Jul 11 15:50:08 2018] ? _raw_spin_unlock_irqrestore+0x46/0x70
>> [Wed Jul 11 15:50:08 2018] ? prepare_to_wait_event+0x191/0x410
>> [Wed Jul 11 15:50:08 2018] ? prepare_to_wait_exclusive+0x210/0x210
>> [Wed Jul 11 15:50:08 2018] ? print_usage_bug+0x3a0/0x3a0
>> [Wed Jul 11 15:50:08 2018] ? do_raw_spin_unlock+0x10f/0x1e0
>> [Wed Jul 11 15:50:08 2018] ? do_raw_spin_trylock+0x120/0x120
>> [Wed Jul 11 15:50:08 2018] schedule+0xca/0x260
>> [Wed Jul 11 15:50:08 2018] ? rcu_lockdep_current_cpu_online+0x12b/0x160
>> [Wed Jul 11 15:50:08 2018] ? __schedule+0x1380/0x1380
>> [Wed Jul 11 15:50:08 2018] ? ___might_sleep+0x126/0x370
>> [Wed Jul 11 15:50:08 2018] ? init_wait_entry+0xc7/0x100
>> [Wed Jul 11 15:50:08 2018] ? __wake_up_locked_key_bookmark+0x20/0x20
>> [Wed Jul 11 15:50:08 2018] ? __btrfs_run_delayed_items+0x1e5/0x280 [btrfs]
>> [Wed Jul 11 15:50:08 2018] ? __might_sleep+0x31/0xd0
>> [Wed Jul 11 15:50:08 2018] btrfs_commit_transaction+0x122a/0x1640 [btrfs]
>> [Wed Jul 11 15:50:08 2018] ? btrfs_apply_pending_changes+0x90/0x90 [btrfs]
>> [Wed Jul 11 15:50:08 2018] ? wait_woken+0x150/0x150
>> [Wed Jul 11 15:50:08 2018] ? ret_from_fork+0x27/0x50
>> [Wed Jul 11 15:50:08 2018] ? ret_from_fork+0x27/0x50
>> [Wed Jul 11 15:50:08 2018] ? deref_stack_reg+0xe0/0xe0
>> [Wed Jul 11 15:50:08 2018] ? __module_text_address+0x63/0xa0
>> [Wed Jul 11 15:50:08 2018] ? preempt_count_sub+0x14/0xc0
>> [Wed Jul 11 15:50:08 2018] ? transaction_kthread+0x161/0x240 [btrfs]
>> [Wed Jul 11 15:50:08 2018] ? is_module_text_address+0x2b/0x50
>> [Wed Jul 11 15:50:08 2018] ? transaction_kthread+0x1d9/0x240 [btrfs]
>> [Wed Jul 11 15:50:08 2018] ? kernel_text_address+0x5a/0x100
>> [Wed Jul 11 15:50:08 2018] ? deactivate_slab.isra.27+0x64f/0x7a0
>> [Wed Jul 11 15:50:08 2018] ? __save_stack_trace+0x82/0x100
>> [Wed Jul 11 15:50:08 2018] ? kasan_kmalloc+0x142/0x170
>> [Wed Jul 11 15:50:08 2018] ? kmem_cache_alloc+0xfc/0x2e0
>> [Wed Jul 11 15:50:08 2018] ? start_transaction+0x596/0x930 [btrfs]
>> [Wed Jul 11 15:50:08 2018] ? transaction_kthread+0x1d9/0x240 [btrfs]
>> [Wed Jul 11 15:50:08 2018] ? kthread+0x1b9/0x1e0
>> [Wed Jul 11 15:50:08 2018] ? ret_from_fork+0x27/0x50
>> [Wed Jul 11 15:50:08 2018] ? deactivate_slab.isra.27+0x64f/0x7a0
>> [Wed Jul 11 15:50:08 2018] ? mark_lock+0x149/0xa80
>> [Wed Jul 11 15:50:08 2018] ? init_object+0x6b/0x80
>> [Wed Jul 11 15:50:08 2018] ? print_usage_bug+0x3a0/0x3a0
>> [Wed Jul 11 15:50:08 2018] ? ___slab_alloc+0x62a/0x690
>> [Wed Jul 11 15:50:08 2018] ? ___slab_alloc+0x62a/0x690
>> [Wed Jul 11 15:50:08 2018] ? __lock_is_held+0x8c/0xe0
>> [Wed Jul 11 15:50:08 2018] ? start_transaction+0x596/0x930 [btrfs]
>> [Wed Jul 11 15:50:08 2018] ? preempt_count_sub+0x14/0xc0
>> [Wed Jul 11 15:50:08 2018] ? rcu_lockdep_current_cpu_online+0x12b/0x160
>> [Wed Jul 11 15:50:08 2018] ? rcu_oom_callback+0x40/0x40
>> [Wed Jul 11 15:50:08 2018] ? __lock_is_held+0x8c/0xe0
>> [Wed Jul 11 15:50:08 2018] ? start_transaction+0x596/0x930 [btrfs]
>> [Wed Jul 11 15:50:08 2018] ? rcu_read_lock_sched_held+0x8f/0xa0
>> [Wed Jul 11 15:50:08 2018] ? btrfs_record_root_in_trans+0x1f/0xa0 [btrfs]
>> [Wed Jul 11 15:50:08 2018] ? start_transaction+0x26b/0x930 [btrfs]
>> [Wed Jul 11 15:50:08 2018] ? btrfs_commit_transaction+0x1640/0x1640 [btrfs]
>> [Wed Jul 11 15:50:08 2018] ? check_flags.part.23+0x240/0x240
>> [Wed Jul 11 15:50:08 2018] ? lock_downgrade+0x380/0x380
>> [Wed Jul 11 15:50:08 2018] ? do_raw_spin_unlock+0x10f/0x1e0
>> [Wed Jul 11 15:50:08 2018] ? do_raw_spin_unlock+0x10f/0x1e0
>> [Wed Jul 11 15:50:08 2018] ? do_raw_spin_trylock+0x120/0x120
>> [Wed Jul 11 15:50:08 2018] transaction_kthread+0x219/0x240 [btrfs]
>> [Wed Jul 11 15:50:08 2018] ? btrfs_cleanup_transaction+0x6f0/0x6f0 [btrfs]
>> [Wed Jul 11 15:50:08 2018] kthread+0x1b9/0x1e0
>> [Wed Jul 11 15:50:08 2018] ? kthread_flush_work_fn+0x10/0x10
>> [Wed Jul 11 15:50:08 2018] ret_from_fork+0x27/0x50
>> [Wed Jul 11 15:50:08 2018]
>> Showing all locks held in the system:
>> [Wed Jul 11 15:50:08 2018] 1 lock held by khungtaskd/72:
>> [Wed Jul 11 15:50:08 2018] #0: 000000006461a1cc (rcu_read_lock){....}, at:
>> debug_show_all_locks+0xa9/0x3d0
>> [Wed Jul 11 15:50:08 2018] 1 lock held by btrfs-transacti/1053:
>> [Wed Jul 11 15:50:08 2018] #0: 000000005d73d46a
>> (&fs_info->transaction_kthread_mutex){+.+.}, at:
>> transaction_kthread+0x92/0x240 [btrfs]
>> [Wed Jul 11 15:50:08 2018] 1 lock held by dmesg/1066:
>> [Wed Jul 11 15:50:08 2018] #0: 000000003e5d6fc4 (&user->lock){+.+.}, at:
>> devkmsg_read+0xa5/0x4f0
>> [Wed Jul 11 15:50:08 2018] 4 locks held by xfs_io/7075:
>>
>> --
>> Thanks,
>> Lu
>>
>>
>> --
>> To unsubscribe from this list: send the line "unsubscribe linux-btrfs" in
>> the body of a message to majord...@vger.kernel.org
>> More majordomo info at http://vger.kernel.org/majordomo-info.html
>
>
>
>--
>Filipe David Manana,
>
>“Whether you think you can, or you think you can't — you're right.”
>
>
--
To unsubscribe from this list: send the line "unsubscribe linux-btrfs" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
