btrfs send -p failing: chown o257-1571-0 failed: No such file or directory

btrfs send -p failing: chown o257-1571-0 failed: No such file or directory

[Massimo B.]

Hello everybody,

trying to use btrbk archive, it's failing with
chown o257-1571-0 failed: No such file or directory.

It is doing a btrbk send -p... | btrbk receive ...:

The command is:
btrfs send -p /mnt/usb/mobiledata/snapshots/mobalindesk/root/root.20200803T060030+0200 /mnt/usb/mobiledata/snapshots/mobalindesk/root/root.20180114T131123+0100 | mbuffer -v 1 -q -m 2% | btrfs receive /mnt/local/data/snapshots/root/

So it takes some newer snapshot as parent to send the older snapshot missing on the target.
Maybe btrbk just selected the wrong parent?
Doing the same without -p is working. What's failing here with the parent?
I tried sending other snapshots with the same parent, but also failing.
We had several discussions about that in the btrbk tickets with the result, it's
a btrfs issue.

I have 3 btrfs. One is my working one, then I have a local backup and a remote
backup. Local backup has less snapshots than the remote backup, so I like to
send some of the remote snapshots back to the local.

Kernel: 5.8.15-gentoo
Could bees have corrupted something? I'm running it on all 3 btrfs.

Best regards,
Massimo

Re: btrfs send -p failing: chown o257-1571-0 failed: No such file or directory

[Filipe Manana]

On Wed, Dec 2, 2020 at 10:22 AM Massimo B. <massimo.b@gmx.net> wrote:
>
> Hello everybody,
>
> trying to use btrbk archive, it's failing with
> chown o257-1571-0 failed: No such file or directory.
>
> It is doing a btrbk send -p... | btrbk receive ...:
>
> The command is:
> btrfs send -p /mnt/usb/mobiledata/snapshots/mobalindesk/root/root.20200803T060030+0200 /mnt/usb/mobiledata/snapshots/mobalindesk/root/root.20180114T131123+0100 | mbuffer -v 1 -q -m 2% | btrfs receive /mnt/local/data/snapshots/root/
>
> So it takes some newer snapshot as parent to send the older snapshot missing on the target.
> Maybe btrbk just selected the wrong parent?
> Doing the same without -p is working. What's failing here with the parent?
> I tried sending other snapshots with the same parent, but also failing.
> We had several discussions about that in the btrbk tickets with the result, it's
> a btrfs issue.

Yes, it's a btrfs issue.
Pretty much there were always bugs where an incremental send generates
wrong path names depending on how things changed between snapshots,
causing the receiving end to fail.
I have fixed several over the years.

>
> I have 3 btrfs. One is my working one, then I have a local backup and a remote
> backup. Local backup has less snapshots than the remote backup, so I like to
> send some of the remote snapshots back to the local.
>
> Kernel: 5.8.15-gentoo

There were two such bug fixes in 5.9 that are not included in a
vanilla 5.8.15 (dunno if gentoo picked them into their 5.8.15 kernel):

https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=98272bb77bf4cc20ed1ffca89832d713e70ebf09
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=9c2b4e0347067396ceb3ae929d6888c81d610259

Might be worth trying them, however I think it's probably a different bug.

> Could bees have corrupted something? I'm running it on all 3 btrfs.

Very unlikely, user applications shouldn't be able to do anything that
corrupts a filesystem.

If those don't solve your problem. then the output of 'btrfs receive
-vvv ...' could be used to help debug the issue.

Thanks.

>
> Best regards,
> Massimo
>


-- 
Filipe David Manana,

“Whether you think you can, or you think you can't — you're right.”

Re: btrfs send -p failing: chown o257-1571-0 failed: No such file or directory

[Massimo B.]

On Wed, 2020-12-02 at 11:04 +0000, Filipe Manana wrote:

> Yes, it's a btrfs issue.

Thanks.
The bug report on btrbk side is:
https://github.com/digint/btrbk/issues/295

> There were two such bug fixes in 5.9 that are not included in a
> vanilla 5.8.15 (dunno if gentoo picked them into their 5.8.15 kernel):

I just switched to the most 5.9.12-gentoo and it's still the same issue.

> If those don't solve your problem. then the output of 'btrfs receive
> -vvv ...' could be used to help debug the issue.

# btrfs send -p /mnt/usb/mobiledata/snapshots/mobalindesk/root/root.20200803T060030+0200 /mnt/usb/mobiledata/snapshots/mobalindesk/root/root.20180114T131123+0100 | mbuffer -v 1 -q -m 2% | btrfs receive -vvv /mnt/local/data/snapshots/root/
At subvol /mnt/usb/mobiledata/snapshots/mobalindesk/root/root.20180114T131123+0100
At snapshot root.20180114T131123+0100
receiving snapshot root.20180114T131123+0100 uuid=dfd895bb-8f3e-ae46-82a5-21e22453a258, ctransid=542345 parent_uuid=95819f51-40a4-9745-9661-7871dce44e19, parent_ctransid=542414
utimes
rename home -> o257-359797-0
mkdir o257-1571-0
rename o257-1571-0 -> .hg
utimes
chown o257-1571-0 - uid=0, gid=0
ERROR: chown o257-1571-0 failed: No such file or directory


Best regards,
Massimo

Re: btrfs send -p failing: chown o257-1571-0 failed: No such file or directory

[Filipe Manana]

On Fri, Dec 4, 2020 at 7:22 AM Massimo B. <massimo.b@gmx.net> wrote:
>
> On Wed, 2020-12-02 at 11:04 +0000, Filipe Manana wrote:
>
> > Yes, it's a btrfs issue.
>
> Thanks.
> The bug report on btrbk side is:
> https://github.com/digint/btrbk/issues/295
>
> > There were two such bug fixes in 5.9 that are not included in a
> > vanilla 5.8.15 (dunno if gentoo picked them into their 5.8.15 kernel):
>
> I just switched to the most 5.9.12-gentoo and it's still the same issue.
>
> > If those don't solve your problem. then the output of 'btrfs receive
> > -vvv ...' could be used to help debug the issue.
>
> # btrfs send -p /mnt/usb/mobiledata/snapshots/mobalindesk/root/root.20200803T060030+0200 /mnt/usb/mobiledata/snapshots/mobalindesk/root/root.20180114T131123+0100 | mbuffer -v 1 -q -m 2% | btrfs receive -vvv /mnt/local/data/snapshots/root/
> At subvol /mnt/usb/mobiledata/snapshots/mobalindesk/root/root.20180114T131123+0100
> At snapshot root.20180114T131123+0100
> receiving snapshot root.20180114T131123+0100 uuid=dfd895bb-8f3e-ae46-82a5-21e22453a258, ctransid=542345 parent_uuid=95819f51-40a4-9745-9661-7871dce44e19, parent_ctransid=542414
> utimes
> rename home -> o257-359797-0
> mkdir o257-1571-0
> rename o257-1571-0 -> .hg
> utimes
> chown o257-1571-0 - uid=0, gid=0
> ERROR: chown o257-1571-0 failed: No such file or directory

Ah, that's interesting.

There are two different inodes with the same number (257) and
different generations (359797 and 1571). Are you using, or ever used,
in that filesystem the mount option "-o inode_cache" (it's deprecated
for a while)?

Even if not, it's still possible to get two different inodes with the
same number, just not very common (specially with such a large
difference in the generation numbers), and send is generally prepared
to deal with such cases, just not this case, and I think I know why it
happens. I'll have to see if I can reproduce it.

If I send you a patch, are you able to patch the kernel, build it and test it?

Thanks.

>
>
> Best regards,
> Massimo
>


-- 
Filipe David Manana,

“Whether you think you can, or you think you can't — you're right.”

Re: btrfs send -p failing: chown o257-1571-0 failed: No such file or directory

[Massimo B.]

On Fri, 2020-12-04 at 10:22 +0000, Filipe Manana wrote:

> Ah, that's interesting.
>
> There are two different inodes with the same number (257) and
> different generations (359797 and 1571). Are you using, or ever used,
> in that filesystem the mount option "-o inode_cache" (it's deprecated
> for a while)?

No.
Which mount options do you need, the sending or the receiving btrfs?
My mount options on the receiving:

/dev/mapper/localdata_crypt on /mnt/autofs/local/data type btrfs (rw,noatime,nodiratime,compress-force=zstd:15,noacl,space_cache=v2,subvolid=5,subvol=/)

Maybe that space_cache=v2 is special.

> Even if not, it's still possible to get two different inodes with the
> same number, just not very common (specially with such a large
> difference in the generation numbers), and send is generally prepared
> to deal with such cases, just not this case, and I think I know why it
> happens. I'll have to see if I can reproduce it.
>
> If I send you a patch, are you able to patch the kernel, build it and test it?

Yes, I will try.

Best regards,
Massimo

Re: btrfs send -p failing: chown o257-1571-0 failed: No such file or directory

[Filipe Manana]

On Fri, Dec 4, 2020 at 1:49 PM Massimo B. <massimo.b@gmx.net> wrote:
>
> On Fri, 2020-12-04 at 10:22 +0000, Filipe Manana wrote:
>
> > Ah, that's interesting.
> >
> > There are two different inodes with the same number (257) and
> > different generations (359797 and 1571). Are you using, or ever used,
> > in that filesystem the mount option "-o inode_cache" (it's deprecated
> > for a while)?
>
> No.
> Which mount options do you need, the sending or the receiving btrfs?

The sending side.
It's not a big deal, even without the inode_cache being ever used,
it's still possible to get into such a situation.

> My mount options on the receiving:
>
> /dev/mapper/localdata_crypt on /mnt/autofs/local/data type btrfs (rw,noatime,nodiratime,compress-force=zstd:15,noacl,space_cache=v2,subvolid=5,subvol=/)
>
> Maybe that space_cache=v2 is special.
>
> > Even if not, it's still possible to get two different inodes with the
> > same number, just not very common (specially with such a large
> > difference in the generation numbers), and send is generally prepared
> > to deal with such cases, just not this case, and I think I know why it
> > happens. I'll have to see if I can reproduce it.
> >
> > If I send you a patch, are you able to patch the kernel, build it and test it?
>
> Yes, I will try.

Great, try this patch then:  https://pastebin.com/raw/8NcPVUb0

I haven't had the time yet to craft a reproducer and confirm that is
the case you are running into, but from the receive -vvv output you
provided before, it seems clear what the problem is.

Thanks.

>
> Best regards,
> Massimo
>


-- 
Filipe David Manana,

“Whether you think you can, or you think you can't — you're right.”

Re: btrfs send -p failing: chown o257-1571-0 failed: No such file or directory

[Massimo B.]

On Fri, 2020-12-04 at 15:00 +0000, Filipe Manana wrote:
> Great, try this patch then:  https://pastebin.com/raw/8NcPVUb0
>
>
>
> I haven't had the time yet to craft a reproducer and confirm that is
>
> the case you are running into, but from the receive -vvv output you
>
> provided before, it seems clear what the problem is.

No, that is not working.
It does not fail anymore and looks like transferring as expected. But the
receiving subvolume is exploding and creating lots of sub directories. I killed
the send|receive processes.

du is far bigger than the origin subvolume and reveals some of those subdirs:

~ du -sh /mnt/local/data/snapshots/root/root.20180114T131123+0100/
du: cannot access '/mnt/local/data/snapshots/root/root.20180114T131123+0100/o1568-359797-0': No such file or directory
du: cannot access '/mnt/local/data/snapshots/root/root.20180114T131123+0100/o6060-359797-0': No such file or directory
du: cannot access '/mnt/local/data/snapshots/root/root.20180114T131123+0100/o9279-359797-0': No such file or directory
du: cannot access '/mnt/local/data/snapshots/root/root.20180114T131123+0100/o19075-359797-0': No such file or directory
du: cannot access '/mnt/local/data/snapshots/root/root.20180114T131123+0100/o19076-359797-0': No such file or directory
...
du: cannot access '/mnt/local/data/snapshots/root/root.20180114T131123+0100/o65078-359798-0': No such file or directory
du: cannot access '/mnt/local/data/snapshots/root/root.20180114T131123+0100/o65084-359798-0': No such file or directory
du: cannot access '/mnt/local/data/snapshots/root/root.20180114T131123+0100/o65095-359798-0': No such file or directory
22G	/mnt/local/data/snapshots/root/root.20180114T131123+0100/

compsize also reports about 20G referenced data.

The origin subvol has only 12G referenced.

Best regards,
Massimo

Re: btrfs send -p failing: chown o257-1571-0 failed: No such file or directory

[Filipe Manana]

On Wed, Dec 9, 2020 at 10:10 AM Massimo B. <massimo.b@gmx.net> wrote:
>
> On Fri, 2020-12-04 at 15:00 +0000, Filipe Manana wrote:
> > Great, try this patch then:  https://pastebin.com/raw/8NcPVUb0
> >
> >
> >
> > I haven't had the time yet to craft a reproducer and confirm that is
> >
> > the case you are running into, but from the receive -vvv output you
> >
> > provided before, it seems clear what the problem is.
>
> No, that is not working.
> It does not fail anymore and looks like transferring as expected. But the
> receiving subvolume is exploding and creating lots of sub directories. I killed
> the send|receive processes.

Just to be clear, you mention that it does not fail anymore but then
you said you killed the processes.
If you kill it and don't let it end, it's not unexpected to have
temporary files/directories.

>
> du is far bigger than the origin subvolume and reveals some of those subdirs:

Ok, that is not unexpected and it can happen often, see below.

>
> ~ du -sh /mnt/local/data/snapshots/root/root.20180114T131123+0100/
> du: cannot access '/mnt/local/data/snapshots/root/root.20180114T131123+0100/o1568-359797-0': No such file or directory
> du: cannot access '/mnt/local/data/snapshots/root/root.20180114T131123+0100/o6060-359797-0': No such file or directory
> du: cannot access '/mnt/local/data/snapshots/root/root.20180114T131123+0100/o9279-359797-0': No such file or directory
> du: cannot access '/mnt/local/data/snapshots/root/root.20180114T131123+0100/o19075-359797-0': No such file or directory
> du: cannot access '/mnt/local/data/snapshots/root/root.20180114T131123+0100/o19076-359797-0': No such file or directory
> ...
> du: cannot access '/mnt/local/data/snapshots/root/root.20180114T131123+0100/o65078-359798-0': No such file or directory
> du: cannot access '/mnt/local/data/snapshots/root/root.20180114T131123+0100/o65084-359798-0': No such file or directory
> du: cannot access '/mnt/local/data/snapshots/root/root.20180114T131123+0100/o65095-359798-0': No such file or directory
> 22G     /mnt/local/data/snapshots/root/root.20180114T131123+0100/
>
> compsize also reports about 20G referenced data.
>
> The origin subvol has only 12G referenced.

Ok, the size differences are not something unexpected - send does not
guarantee the sizes are preserved, neither does guarantee the same
extent layout as the source.
There are mainly two reasons for that:

1) Send currently doesn't have a command for hole punching, so holes
are considered a write full of zeros - if there's a 1G hole for
example, it's sent as a write operation with 1G zeros;

2) Sometimes shared extents are sent as regular writes and not clone
commands, one of the reasons for that is that when there are many
references for an extent, it's too slow to iterate its backreferences.
Also in a few corner cases we skip extent cloning.

I haven't got yet the chance to work on that, but at least that patch
fixes one type of problem, maybe you are hitting other different
problems too.

So to confirm if there are other problems, you really need to let send
and receive processes finish (don't kill them). If they finish without
failure, then check if temporary directories (or files with the same
name pattern) still exist or not.

Thanks.

>
> Best regards,
> Massimo
>


-- 
Filipe David Manana,

“Whether you think you can, or you think you can't — you're right.”

Re: btrfs send -p failing: chown o257-1571-0 failed: No such file or directory

[Massimo B.]

On Wed, 2020-12-09 at 10:29 +0000, Filipe Manana wrote:
> So to confirm if there are other problems, you really need to let send and
> receive processes finish (don't kill them). If they finish without failure,
> then check if temporary directories (or files with the same name pattern)
> still exist or not.

Ok, it seems to be working.
Thank you very much.

Can you put a note on the list here, when this is going to be released and to
which version?

Best regards,
Massimo

Re: btrfs send -p failing: chown o257-1571-0 failed: No such file or directory

[Filipe Manana]

On Thu, Dec 10, 2020 at 6:23 AM Massimo B. <massimo.b@gmx.net> wrote:
>
> On Wed, 2020-12-09 at 10:29 +0000, Filipe Manana wrote:
> > So to confirm if there are other problems, you really need to let send and
> > receive processes finish (don't kill them). If they finish without failure,
> > then check if temporary directories (or files with the same name pattern)
> > still exist or not.
>
> Ok, it seems to be working.
> Thank you very much.
>
> Can you put a note on the list here, when this is going to be released and to
> which version?

Sure.
Thanks for testing it!

>
> Best regards,
> Massimo
>


-- 
Filipe David Manana,

“Whether you think you can, or you think you can't — you're right.”

Re: btrfs send -p failing: chown o257-1571-0 failed: No such file or directory

[Massimo B.]

On Wed, 2020-12-09 at 10:29 +0000, Filipe Manana wrote:
> So to confirm if there are other problems, you really need to let send
>
> and receive processes finish (don't kill them). If they finish without
>
> failure, then check if temporary directories (or files with the same
>
> name pattern) still exist or not.

I continued with send|receive successfully with a lot of snapshots, then I found
some new error. Is this also related?

clone mb/Documents.AZ/0.SYNC/....pdf - source=mb/Documents.AZ/0.SYNC/....pdf source offset=20705280 offset=20709376 length=4096
clone mb/Documents.AZ/0.SYNC/....pdf - source=mb/Documents.AZ/0.SYNC/....pdf source offset=20713472 offset=20713472 length=4096
ERROR: failed to clone extents to mb/Documents.AZ/0.SYNC/....pdf: Invalid argument

Best regards,
Massimo

Re: btrfs send -p failing: chown o257-1571-0 failed: No such file or directory

[Filipe Manana]

On Sun, Dec 13, 2020 at 9:55 AM Massimo B. <massimo.b@gmx.net> wrote:
>
> On Wed, 2020-12-09 at 10:29 +0000, Filipe Manana wrote:
> > So to confirm if there are other problems, you really need to let send
> >
> > and receive processes finish (don't kill them). If they finish without
> >
> > failure, then check if temporary directories (or files with the same
> >
> > name pattern) still exist or not.
>
> I continued with send|receive successfully with a lot of snapshots, then I found
> some new error. Is this also related?
>
> clone mb/Documents.AZ/0.SYNC/....pdf - source=mb/Documents.AZ/0.SYNC/....pdf source offset=20705280 offset=20709376 length=4096
> clone mb/Documents.AZ/0.SYNC/....pdf - source=mb/Documents.AZ/0.SYNC/....pdf source offset=20713472 offset=20713472 length=4096
> ERROR: failed to clone extents to mb/Documents.AZ/0.SYNC/....pdf: Invalid argument

It's a different problem. This one because the kernel is sending an
invalid clone operation - the source and destination offsets are the
same, which makes the receiver fail.
Can you tell what's the size (in bytes) of "mb/Documents.AZ/0.SYNC"
after the receive fails? Both in the destination and source.

I'll look into it.

Thanks.

>
> Best regards,
> Massimo
>


-- 
Filipe David Manana,

“Whether you think you can, or you think you can't — you're right.”

Re: btrfs send -p failing: chown o257-1571-0 failed: No such file or directory

[Massimo B.]

On Mon, 2020-12-14 at 09:46 +0000, Filipe Manana wrote:

> clone mb/Documents.AZ/0.SYNC/....pdf - source=mb/Documents.AZ/0.SYNC/....pdf
> > source offset=20705280 offset=20709376 length=4096
> > clone mb/Documents.AZ/0.SYNC/....pdf - source=mb/Documents.AZ/0.SYNC/....pdf
> > source offset=20713472 offset=20713472 length=4096
> > ERROR: failed to clone extents to mb/Documents.AZ/0.SYNC/....pdf: Invalid
> > argument
>
> It's a different problem. This one because the kernel is sending an
> invalid clone operation - the source and destination offsets are the
> same, which makes the receiver fail.
> Can you tell what's the size (in bytes) of "mb/Documents.AZ/0.SYNC"
> after the receive fails? Both in the destination and source.

Hi Filipe,

I already deleted the failing subvolume, now I got the issue again. Here are the
detailed information about the file:


# btrfs send /mnt/usb/mobiledata/snapshots/mobalindesk/vm/VirtualMachines.20190621T140904+0200 | mbuffer -v 1 -m 2% | btrfs receive /mnt/local/data/snapshots/vm/
...
write IE8 - Win7/IE8 - Win7-disk1.vmdk - offset=4742344704 length=4096
clone IE8 - Win7/IE8 - Win7-disk1.vmdk - source=IE8 - Win7/IE8 - Win7-disk1.vmdk source offset=4742184960 offset=4742348800 length=16384
clone IE8 - Win7/IE8 - Win7-disk1.vmdk - source=IE8 - Win7/IE8 - Win7-disk1.vmdk source offset=4742184960 offset=4742365184 length=28672
clone IE8 - Win7/IE8 - Win7-disk1.vmdk - source=IE8 - Win7/IE8 - Win7-disk1.vmdk source offset=4742246400 offset=4742393856 length=8192
write IE8 - Win7/IE8 - Win7-disk1.vmdk - offset=4742402048 length=12288
clone IE8 - Win7/IE8 - Win7-disk1.vmdk - source=IE8 - Win7/IE8 - Win7-disk1.vmdk source offset=4742410240 offset=4742414336 length=4096
clone IE8 - Win7/IE8 - Win7-disk1.vmdk - source=IE8 - Win7/IE8 - Win7-disk1.vmdk source offset=4742418432 offset=4742418432 length=4096
ERROR: failed to clone extents to IE8 - Win7/IE8 - Win7-disk1.vmdk: Invalid argument

summary: 4226 MiByte in 21min 11.4sec - average of 3404 kiB/s


# ls -al "/mnt/usb/mobiledata/snapshots/mobalindesk/vm/VirtualMachines.20190621T140904+0200/IE8 - Win7/IE8 - Win7-disk1.vmdk"
-rw------- 1 massimo massimo 17932222464 18. Dez 2018  '/mnt/usb/mobiledata/snapshots/mobalindesk/vm/VirtualMachines.20190621T140904+0200/IE8 - Win7/IE8 - Win7-disk1.vmdk'

# ls -al "/mnt/local/data/snapshots/vm/VirtualMachines.20190621T140904+0200/IE8 - Win7/IE8 - Win7-disk1.vmdk"
-rw------- 1 root root 4742418432 18. Dez 07:37 '/mnt/local/data/snapshots/vm/VirtualMachines.20190621T140904+0200/IE8 - Win7/IE8 - Win7-disk1.vmdk'

# compsize "/mnt/usb/mobiledata/snapshots/mobalindesk/vm/VirtualMachines.20190621T140904+0200/IE8 - Win7/IE8 - Win7-disk1.vmdk"
Type       Perc     Disk Usage   Uncompressed Referenced
TOTAL       45%      7.3G          16G          16G
none       100%      1.9G         1.9G         2.3G
zlib        38%      4.8G          12G          13G
zstd        34%      536M         1.5G         727M

# compsize "/mnt/local/data/snapshots/vm/VirtualMachines.20190621T140904+0200/IE8 - Win7/IE8 - Win7-disk1.vmdk"
Type       Perc     Disk Usage   Uncompressed Referenced
TOTAL       92%      4.1G         4.4G         4.3G
none       100%      3.8G         3.8G         3.8G
zlib        32%      7.3M          22M          22M
zstd        45%      264M         583M         560M

Does that help you?

Best regards,
Massimo

Re: btrfs send -p failing: chown o257-1571-0 failed: No such file or directory

[Filipe Manana]

On Fri, Dec 18, 2020 at 7:25 AM Massimo B. <massimo.b@gmx.net> wrote:
>
> On Mon, 2020-12-14 at 09:46 +0000, Filipe Manana wrote:
>
> > clone mb/Documents.AZ/0.SYNC/....pdf - source=mb/Documents.AZ/0.SYNC/....pdf
> > > source offset=20705280 offset=20709376 length=4096
> > > clone mb/Documents.AZ/0.SYNC/....pdf - source=mb/Documents.AZ/0.SYNC/....pdf
> > > source offset=20713472 offset=20713472 length=4096
> > > ERROR: failed to clone extents to mb/Documents.AZ/0.SYNC/....pdf: Invalid
> > > argument
> >
> > It's a different problem. This one because the kernel is sending an
> > invalid clone operation - the source and destination offsets are the
> > same, which makes the receiver fail.
> > Can you tell what's the size (in bytes) of "mb/Documents.AZ/0.SYNC"
> > after the receive fails? Both in the destination and source.
>
> Hi Filipe,
>
> I already deleted the failing subvolume, now I got the issue again. Here are the
> detailed information about the file:
>
>
> # btrfs send /mnt/usb/mobiledata/snapshots/mobalindesk/vm/VirtualMachines.20190621T140904+0200 | mbuffer -v 1 -m 2% | btrfs receive /mnt/local/data/snapshots/vm/
> ...
> write IE8 - Win7/IE8 - Win7-disk1.vmdk - offset=4742344704 length=4096
> clone IE8 - Win7/IE8 - Win7-disk1.vmdk - source=IE8 - Win7/IE8 - Win7-disk1.vmdk source offset=4742184960 offset=4742348800 length=16384
> clone IE8 - Win7/IE8 - Win7-disk1.vmdk - source=IE8 - Win7/IE8 - Win7-disk1.vmdk source offset=4742184960 offset=4742365184 length=28672
> clone IE8 - Win7/IE8 - Win7-disk1.vmdk - source=IE8 - Win7/IE8 - Win7-disk1.vmdk source offset=4742246400 offset=4742393856 length=8192
> write IE8 - Win7/IE8 - Win7-disk1.vmdk - offset=4742402048 length=12288
> clone IE8 - Win7/IE8 - Win7-disk1.vmdk - source=IE8 - Win7/IE8 - Win7-disk1.vmdk source offset=4742410240 offset=4742414336 length=4096
> clone IE8 - Win7/IE8 - Win7-disk1.vmdk - source=IE8 - Win7/IE8 - Win7-disk1.vmdk source offset=4742418432 offset=4742418432 length=4096
> ERROR: failed to clone extents to IE8 - Win7/IE8 - Win7-disk1.vmdk: Invalid argument
>
> summary: 4226 MiByte in 21min 11.4sec - average of 3404 kiB/s
>
>
> # ls -al "/mnt/usb/mobiledata/snapshots/mobalindesk/vm/VirtualMachines.20190621T140904+0200/IE8 - Win7/IE8 - Win7-disk1.vmdk"
> -rw------- 1 massimo massimo 17932222464 18. Dez 2018  '/mnt/usb/mobiledata/snapshots/mobalindesk/vm/VirtualMachines.20190621T140904+0200/IE8 - Win7/IE8 - Win7-disk1.vmdk'
>
> # ls -al "/mnt/local/data/snapshots/vm/VirtualMachines.20190621T140904+0200/IE8 - Win7/IE8 - Win7-disk1.vmdk"
> -rw------- 1 root root 4742418432 18. Dez 07:37 '/mnt/local/data/snapshots/vm/VirtualMachines.20190621T140904+0200/IE8 - Win7/IE8 - Win7-disk1.vmdk'
>
> # compsize "/mnt/usb/mobiledata/snapshots/mobalindesk/vm/VirtualMachines.20190621T140904+0200/IE8 - Win7/IE8 - Win7-disk1.vmdk"
> Type       Perc     Disk Usage   Uncompressed Referenced
> TOTAL       45%      7.3G          16G          16G
> none       100%      1.9G         1.9G         2.3G
> zlib        38%      4.8G          12G          13G
> zstd        34%      536M         1.5G         727M
>
> # compsize "/mnt/local/data/snapshots/vm/VirtualMachines.20190621T140904+0200/IE8 - Win7/IE8 - Win7-disk1.vmdk"
> Type       Perc     Disk Usage   Uncompressed Referenced
> TOTAL       92%      4.1G         4.4G         4.3G
> none       100%      3.8G         3.8G         3.8G
> zlib        32%      7.3M          22M          22M
> zstd        45%      264M         583M         560M
>
> Does that help you?

It confirms what I suspected and narrows down a bit the possible causes.
Are you able to run the send operation again with the following debug path?

https://pastebin.com/raw/cEEy9A6W

When the issue happens it should dump to dmesg/syslog a debug message
that starts with the marker "HERE" and right before it,
something that takes several lines to dump a metadata leaf, and with
first line being something like this:

"leaf <number> gen <number> total ptrs <number> free space <number>
owner <number>"

That way I can see the specific extent metadata layout that causes
send to issue an invalid clone operation (attempting to clone 4096
bytes from eof).

Thanks a lot Massimo!

>
> Best regards,
> Massimo
>


-- 
Filipe David Manana,

“Whether you think you can, or you think you can't — you're right.”

Re: btrfs send -p failing: chown o257-1571-0 failed: No such file or directory

[Filipe Manana]

On Fri, Dec 18, 2020 at 11:44 AM Filipe Manana <fdmanana@gmail.com> wrote:
>
> On Fri, Dec 18, 2020 at 7:25 AM Massimo B. <massimo.b@gmx.net> wrote:
> >
> > On Mon, 2020-12-14 at 09:46 +0000, Filipe Manana wrote:
> >
> > > clone mb/Documents.AZ/0.SYNC/....pdf - source=mb/Documents.AZ/0.SYNC/....pdf
> > > > source offset=20705280 offset=20709376 length=4096
> > > > clone mb/Documents.AZ/0.SYNC/....pdf - source=mb/Documents.AZ/0.SYNC/....pdf
> > > > source offset=20713472 offset=20713472 length=4096
> > > > ERROR: failed to clone extents to mb/Documents.AZ/0.SYNC/....pdf: Invalid
> > > > argument
> > >
> > > It's a different problem. This one because the kernel is sending an
> > > invalid clone operation - the source and destination offsets are the
> > > same, which makes the receiver fail.
> > > Can you tell what's the size (in bytes) of "mb/Documents.AZ/0.SYNC"
> > > after the receive fails? Both in the destination and source.
> >
> > Hi Filipe,
> >
> > I already deleted the failing subvolume, now I got the issue again. Here are the
> > detailed information about the file:
> >
> >
> > # btrfs send /mnt/usb/mobiledata/snapshots/mobalindesk/vm/VirtualMachines.20190621T140904+0200 | mbuffer -v 1 -m 2% | btrfs receive /mnt/local/data/snapshots/vm/
> > ...
> > write IE8 - Win7/IE8 - Win7-disk1.vmdk - offset=4742344704 length=4096
> > clone IE8 - Win7/IE8 - Win7-disk1.vmdk - source=IE8 - Win7/IE8 - Win7-disk1.vmdk source offset=4742184960 offset=4742348800 length=16384
> > clone IE8 - Win7/IE8 - Win7-disk1.vmdk - source=IE8 - Win7/IE8 - Win7-disk1.vmdk source offset=4742184960 offset=4742365184 length=28672
> > clone IE8 - Win7/IE8 - Win7-disk1.vmdk - source=IE8 - Win7/IE8 - Win7-disk1.vmdk source offset=4742246400 offset=4742393856 length=8192
> > write IE8 - Win7/IE8 - Win7-disk1.vmdk - offset=4742402048 length=12288
> > clone IE8 - Win7/IE8 - Win7-disk1.vmdk - source=IE8 - Win7/IE8 - Win7-disk1.vmdk source offset=4742410240 offset=4742414336 length=4096
> > clone IE8 - Win7/IE8 - Win7-disk1.vmdk - source=IE8 - Win7/IE8 - Win7-disk1.vmdk source offset=4742418432 offset=4742418432 length=4096
> > ERROR: failed to clone extents to IE8 - Win7/IE8 - Win7-disk1.vmdk: Invalid argument
> >
> > summary: 4226 MiByte in 21min 11.4sec - average of 3404 kiB/s
> >
> >
> > # ls -al "/mnt/usb/mobiledata/snapshots/mobalindesk/vm/VirtualMachines.20190621T140904+0200/IE8 - Win7/IE8 - Win7-disk1.vmdk"
> > -rw------- 1 massimo massimo 17932222464 18. Dez 2018  '/mnt/usb/mobiledata/snapshots/mobalindesk/vm/VirtualMachines.20190621T140904+0200/IE8 - Win7/IE8 - Win7-disk1.vmdk'
> >
> > # ls -al "/mnt/local/data/snapshots/vm/VirtualMachines.20190621T140904+0200/IE8 - Win7/IE8 - Win7-disk1.vmdk"
> > -rw------- 1 root root 4742418432 18. Dez 07:37 '/mnt/local/data/snapshots/vm/VirtualMachines.20190621T140904+0200/IE8 - Win7/IE8 - Win7-disk1.vmdk'
> >
> > # compsize "/mnt/usb/mobiledata/snapshots/mobalindesk/vm/VirtualMachines.20190621T140904+0200/IE8 - Win7/IE8 - Win7-disk1.vmdk"
> > Type       Perc     Disk Usage   Uncompressed Referenced
> > TOTAL       45%      7.3G          16G          16G
> > none       100%      1.9G         1.9G         2.3G
> > zlib        38%      4.8G          12G          13G
> > zstd        34%      536M         1.5G         727M
> >
> > # compsize "/mnt/local/data/snapshots/vm/VirtualMachines.20190621T140904+0200/IE8 - Win7/IE8 - Win7-disk1.vmdk"
> > Type       Perc     Disk Usage   Uncompressed Referenced
> > TOTAL       92%      4.1G         4.4G         4.3G
> > none       100%      3.8G         3.8G         3.8G
> > zlib        32%      7.3M          22M          22M
> > zstd        45%      264M         583M         560M
> >
> > Does that help you?
>
> It confirms what I suspected and narrows down a bit the possible causes.
> Are you able to run the send operation again with the following debug path?
>
> https://pastebin.com/raw/cEEy9A6W

Well, never mind, in the meanwhile after the holidays I find out why it happens.
The patch with the fix is at:

https://patchwork.kernel.org/project/linux-btrfs/patch/900493c40f7edbd42fe861ccd9a68851ea952499.1610363502.git.fdmanana@suse.com/

Thanks.

>
> When the issue happens it should dump to dmesg/syslog a debug message
> that starts with the marker "HERE" and right before it,
> something that takes several lines to dump a metadata leaf, and with
> first line being something like this:
>
> "leaf <number> gen <number> total ptrs <number> free space <number>
> owner <number>"
>
> That way I can see the specific extent metadata layout that causes
> send to issue an invalid clone operation (attempting to clone 4096
> bytes from eof).
>
> Thanks a lot Massimo!
>
> >
> > Best regards,
> > Massimo
> >
>
>
> --
> Filipe David Manana,
>
> “Whether you think you can, or you think you can't — you're right.”



-- 
Filipe David Manana,

“Whether you think you can, or you think you can't — you're right.”