Re: Lockups with btrfs on 3.16-rc1 - bisected

[Tsutomu Itoh <t-itoh@jp.fujitsu.com>]

On 2014/06/20 8:21, Waiman Long wrote:
> On 06/19/2014 05:50 PM, Chris Mason wrote:
>>>>
>>>> I would like to take back my comments. I took out the read_lock, but the
>>>> process still hang while doing file activities on btrfs filesystem. So
>>>> the problem is trickier than I thought. Below are the stack backtraces
>>>> of some of the relevant processes.
>>>>
>>> You weren't wrong, but it was also the tree trylock code.  Our trylocks
>>> only back off if the blocking lock is held.  btrfs_next_leaf needs it to
>>> be a true trylock.  The confusing part is this hasn't really changed,
>>> but one of the callers must be a spinner where we used to have a blocker.
>> This is what I have queued up, it's working here.
>>
>> -chris
>>
>> commit ea4ebde02e08558b020c4b61bb9a4c0fcf63028e
>> Author: Chris Mason<clm@fb.com>
>> Date:   Thu Jun 19 14:16:52 2014 -0700
>>
>>      Btrfs: fix deadlocks with trylock on tree nodes
>>
>>      The Btrfs tree trylock function is poorly named.  It always takes
>>      the spinlock and backs off if the blocking lock is held.  This
>>      can lead to surprising lockups because people expect it to really be a
>>      trylock.
>>
>>      This commit makes it a pure trylock, both for the spinlock and the
>>      blocking lock.  It also reworks the nested lock handling slightly to
>>      avoid taking the read lock while a spinning write lock might be held.
>>
>>      Signed-off-by: Chris Mason<clm@fb.com>
>
> I didn't realize that those non-blocking lock functions are really trylocks. Yes, the patch did seem to fix the hanging problem that I saw when I just untar the kernel source files into a btrfs filesystem. However, when I tried did a kernel build on a 24-thread (-j 24) system, the build process hanged after a while. The following kind of stack trace messages were printed:
>
> INFO: task btrfs-transacti:16576 blocked for more than 120 seconds.
>        Tainted: G            E 3.16.0-rc1 #5
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> btrfs-transacti D 000000000000000f     0 16576      2 0x00000000
>   ffff88080eabbbf8 0000000000000046 ffff880803b98350 ffff88080eab8010
>   0000000000012b80 0000000000012b80 ffff880805ed8f10 ffff88080d162310
>   ffff88080eabbce8 ffff8807be170880 ffff8807be170888 7fffffffffffffff
> Call Trace:
>   [<ffffffff81592de9>] schedule+0x29/0x70
>   [<ffffffff815920bd>] schedule_timeout+0x13d/0x1d0
>   [<ffffffff8106b474>] ? wake_up_worker+0x24/0x30
>   [<ffffffff8106d595>] ? insert_work+0x65/0xb0
>   [<ffffffff81593cc6>] wait_for_completion+0xc6/0x100
>   [<ffffffff810868d0>] ? try_to_wake_up+0x220/0x220
>   [<ffffffffa06bb9ba>] btrfs_wait_and_free_delalloc_work+0x1a/0x30 [btrfs]
>   [<ffffffffa06d458d>] btrfs_run_ordered_operations+0x1dd/0x2c0 [btrfs]
>   [<ffffffffa06b7fd5>] btrfs_flush_all_pending_stuffs+0x35/0x40 [btrfs]
>   [<ffffffffa06ba099>] btrfs_commit_transaction+0x229/0xa30 [btrfs]
>   [<ffffffff8105ef30>] ? lock_timer_base+0x70/0x70
>   [<ffffffffa06b51db>] transaction_kthread+0x1eb/0x270 [btrfs]
>   [<ffffffffa06b4ff0>] ? close_ctree+0x2d0/0x2d0 [btrfs]
>   [<ffffffff8107544e>] kthread+0xce/0xf0
>   [<ffffffff81075380>] ? kthread_freezable_should_stop+0x70/0x70
>   [<ffffffff8159636c>] ret_from_fork+0x7c/0xb0
>   [<ffffffff81075380>] ? kthread_freezable_should_stop+0x70/0x70
>
> It looks like some more work may still be needed. Or it could be a problem in my system configuration.
>

Umm, after applying Chris's patch to my environment, xfstests ran
completely and the above messages were not output. (Are above messages
another bug?)

Thanks,
Tsutomu