Re: bisected: btrfs dedupe regression in v5.11-rc1: 3078d85c9a10 vfs: verify source area in vfs_dedupe_file_range_one()

Zygo Blaxell
2021-12-17T20:50:46Z

On Thu, Dec 16, 2021 at 05:07:50PM -0500, Josef Bacik wrote:
> On Thu, Dec 16, 2021 at 11:29:06PM +0200, Nikolay Borisov wrote:
> >
> >
> > On 16.12.21 г. 7:33, Zygo Blaxell wrote:
> > > On Wed, Dec 15, 2021 at 12:25:04AM +0200, Nikolay Borisov wrote:
> > >> Huhz, this means there is an open transaction handle somewhere o_O. I
> > >> checked back the stacktraces in your original email but couldn't see
> > >> where that might be coming from. I.e all processes are waiting on
> > >> wait_current_trans and this happens _before_ the transaction handle is
> > >> opened, hence num_extwriters can't have been incremented by them.
> > >>
> > >> When an fs wedges, and you get again num_extwriters can you provde the
> > >> output of "echo w > /proc/sysrq-trigger"
> > >
> > > Here you go...
> >
> > <snip>
> >
> > >
> > > Again we have "3 locks held" but no list of locks. WTF is 10883 doing?
> > > Well, first of all it's using 100% CPU in the kernel. Some samples of
> > > kernel stacks:
> > >
> > > # cat /proc/*/task/10883/stack
> > > [<0>] down_read_nested+0x32/0x140
> > > [<0>] __btrfs_tree_read_lock+0x2d/0x110
> > > [<0>] btrfs_tree_read_lock+0x10/0x20
> > > [<0>] btrfs_search_old_slot+0x627/0x8a0
> > > [<0>] btrfs_next_old_leaf+0xcb/0x340
> > > [<0>] find_parent_nodes+0xcd7/0x1c40
> > > [<0>] btrfs_find_all_leafs+0x63/0xb0
> > > [<0>] iterate_extent_inodes+0xc8/0x270
> > > [<0>] iterate_inodes_from_logical+0x9f/0xe0
> >
> > That's the real culprit, in this case we are not searching the commit
> > root hence we've attached to the transaction. So we are doing backref
> > resolution which either:
> >
> > a) Hits some pathological case and loops for very long time, backref
> > resolution is known to take a lot of time.
> >
> > b) We hit a bug in backref resolution and loop forever which again
> > results in the transaction being kept open.
> >
> > Now I wonder why you were able to bisect this to the seemingly unrelated
> > commit in the vfs code.
> >
> > Josef any ideas how to proceed further to debug why backref resolution
> > takes a long time and if it's just an infinite loop?
> >
>
> It's probably an infinite loop, I'd just start with something like this
>
> bpftrace -e 'tracepoint:btrfs:btrfs_prelim_ref_insert { printf("bytenr is %llu", args->bytenr); }'
>
> and see if it's spitting out the same shit over and over again. If it is can I
> get a btrfs inspect-internal dump-tree -e on the device along with the bytenr
> it's hung up on so I can figure out wtf it's tripping over?

That bpftrace command doesn't output anything after the hang. Before the
hang, it's thousands and thousands of values changing as bees moves around
the filesystem.

> If it's not looping there, it may be looping higher up, but I don't see where it
> would be doing that. Lets start here and work our way up if we need to.
> Thanks,
>
> Josef