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

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:

quoted

On 16.12.21 г. 7:33, Zygo Blaxell wrote:

quoted

On Wed, Dec 15, 2021 at 12:25:04AM +0200, Nikolay Borisov wrote:

quoted

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>

quoted

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