search

kdave / btrfs-progs

Development of userspace BTRFS tools
GNU General Public License v2.0
527 stars 239 forks source link

btrfs initial full receive fails with "ERROR: failed to clone extents ..." #787

Open SteveElliott opened 1 month ago

SteveElliott commented 1 month ago

With an empty receive directory ...

[steve@colt btrfs] $ ls -latr /mnt/ReceivedSnaps/
total 16
drwxr-xr-x. 1 root root 88 May  2 14:40 ..
drwxr-xr-x  1 root root  0 May  3 15:23 .

A send/receive runs ...

[steve@colt btrfs] $ sudo btrfs send --no-data --compressed-data /tmp/top/SnapsToSend/2024-05-03T15\:06\:52+10\:00_@/ | sudo btrfs receive /mnt/ReceivedSnaps/ -vv 2> receive-vv.log
At subvol /tmp/top/SnapsToSend/2024-05-03T15:06:52+10:00_@/

... and reports a failure.

[steve@colt btrfs] $ tail -n 7 receive-vv.log 
utimes usr/lib/modules/5.15.5-100.fc34.x86_64/modules.builtin.alias.bin
mkfile o4838181-225221-0
rename o4838181-225221-0 -> usr/lib/qt5/plugins/bcompare_ext_kde.so
utimes var/lib/flatpak/repo/objects/c1
set_xattr usr/lib/qt5/plugins/bcompare_ext_kde.so - name=security.selinux data_len=31 data=unconfined_u:object_r:lib_t:s0
clone usr/lib/qt5/plugins/bcompare_ext_kde.so - source=usr/lib64/qt5/plugins/bcompare_ext_kde.so source offset=0 offset=0 length=131072
ERROR: failed to clone extents to usr/lib/qt5/plugins/bcompare_ext_kde.so: Invalid argument

A closer inspection shows that an attempt is made to clone the lib version of the target file from the lib64 version.

[steve@colt btrfs] $ grep -C 6 bcompare_ext receive-vv.log 
>8..snip..>8
mkfile o315129-17403-0
rename o315129-17403-0 -> usr/lib64/qt5/plugins/bcompare_ext_kde.so
utimes usr/lib64/python2.7/lib-tk/test
set_xattr usr/lib64/qt5/plugins/bcompare_ext_kde.so - name=security.selinux data_len=27 data=system_u:object_r:lib_t:s0
update_extent usr/lib64/qt5/plugins/bcompare_ext_kde.so: offset=0, len=131072
update_extent usr/lib64/qt5/plugins/bcompare_ext_kde.so: offset=131072, len=131072
update_extent usr/lib64/qt5/plugins/bcompare_ext_kde.so: offset=262144, len=131072
update_extent usr/lib64/qt5/plugins/bcompare_ext_kde.so: offset=393216, len=78600
chown usr/lib64/qt5/plugins/bcompare_ext_kde.so - uid=0, gid=0
chmod usr/lib64/qt5/plugins/bcompare_ext_kde.so - mode=0755
utimes usr/lib64/qt5/plugins/bcompare_ext_kde.so
>8 ..snip.. >8
--
>8 ..snip.. >8
mkfile o4838181-225221-0
rename o4838181-225221-0 -> usr/lib/qt5/plugins/bcompare_ext_kde.so
utimes var/lib/flatpak/repo/objects/c1
set_xattr usr/lib/qt5/plugins/bcompare_ext_kde.so - name=security.selinux data_len=31 data=unconfined_u:object_r:lib_t:s0
clone usr/lib/qt5/plugins/bcompare_ext_kde.so - source=usr/lib64/qt5/plugins/bcompare_ext_kde.so source offset=0 offset=0 length=131072
ERROR: failed to clone extents to usr/lib/qt5/plugins/bcompare_ext_kde.so: Invalid argument

This is attempted even though the source files have distinct inodes and no parent subvols are involved.

[steve@colt btrfs] $ ls -lai /usr/lib/qt5/plugins/bcompare_ext_kde.so 
4838181 -rwxr-xr-x. 1 root root 471816 Feb 17 15:54 /usr/lib/qt5/plugins/bcompare_ext_kde.so
[steve@colt btrfs] $ ls -lai /usr/lib64/qt5/plugins/bcompare_ext_kde.so 
315129 -rwxr-xr-x. 1 root root 471816 Feb 17 15:54 /usr/lib64/qt5/plugins/bcompare_ext_kde.so
[steve@colt btrfs] $

My software versions ....

[steve@colt btrfs] $ uname -a
Linux colt 6.8.7-100.fc38.x86_64 #1 SMP PREEMPT_DYNAMIC Wed Apr 17 19:34:28 UTC 2024 x86_64 GNU/Linux
[steve@colt btrfs] $ cat /etc/fedora-release
Fedora release 38 (Thirty Eight)
[steve@colt btrfs] $ bash --version
GNU bash, version 5.2.26(1)-release (x86_64-redhat-linux-gnu)
[steve@colt btrfs] $ btrfs --version
btrfs-progs v6.8
SteveElliott commented 1 month ago

Further investigation indicates that the 2 source files share extents on both the original FS and the snap.

[steve@colt btrfs] $ filefrag -ev /usr/lib64/qt5/plugins/bcompare_ext_kde.so 
Filesystem type is: 9123683e
File size of /usr/lib64/qt5/plugins/bcompare_ext_kde.so is 471816 (116 blocks of 4096 bytes)
 ext:     logical_offset:        physical_offset: length:   expected: flags:
   0:        0..      31:   45341441..  45341472:     32:             encoded,shared
   1:       32..      63:   45341456..  45341487:     32:   45341473: encoded,shared
   2:       64..      95:   45341469..  45341500:     32:   45341488: encoded,shared
   3:       96..     115:   45326531..  45326550:     20:   45341501: last,encoded,shared,eof
/usr/lib64/qt5/plugins/bcompare_ext_kde.so: 4 extents found

[steve@colt btrfs] $ filefrag -ev /usr/lib/qt5/plugins/bcompare_ext_kde.so 
Filesystem type is: 9123683e
File size of /usr/lib/qt5/plugins/bcompare_ext_kde.so is 471816 (116 blocks of 4096 bytes)
 ext:     logical_offset:        physical_offset: length:   expected: flags:
   0:        0..      31:   45341441..  45341472:     32:             encoded,shared
   1:       32..      63:   45341456..  45341487:     32:   45341473: encoded,shared
   2:       64..      95:   45341469..  45341500:     32:   45341488: encoded,shared
   3:       96..     115:   45326531..  45326550:     20:   45341501: last,encoded,shared,eof
/usr/lib/qt5/plugins/bcompare_ext_kde.so: 4 extents found

[steve@colt btrfs] $ filefrag -ev /tmp/top/SnapsToSend/2024-05-04T14\:39\:45+10\:00_@/usr/lib/qt5/plugins/bcompare_ext_kde.so 
Filesystem type is: 9123683e
File size of /tmp/top/SnapsToSend/2024-05-04T14:39:45+10:00_@/usr/lib/qt5/plugins/bcompare_ext_kde.so is 471816 (116 blocks of 4096 bytes)
 ext:     logical_offset:        physical_offset: length:   expected: flags:
   0:        0..      31:   45341441..  45341472:     32:             encoded,shared
   1:       32..      63:   45341456..  45341487:     32:   45341473: encoded,shared
   2:       64..      95:   45341469..  45341500:     32:   45341488: encoded,shared
   3:       96..     115:   45326531..  45326550:     20:   45341501: last,encoded,shared,eof
/tmp/top/SnapsToSend/2024-05-04T14:39:45+10:00_@/usr/lib/qt5/plugins/bcompare_ext_kde.so: 4 extents found

[steve@colt btrfs] $ filefrag -ev /tmp/top/SnapsToSend/2024-05-04T14\:39\:45+10\:00_@/usr/lib64/qt5/plugins/bcompare_ext_kde.so 
Filesystem type is: 9123683e
File size of /tmp/top/SnapsToSend/2024-05-04T14:39:45+10:00_@/usr/lib64/qt5/plugins/bcompare_ext_kde.so is 471816 (116 blocks of 4096 bytes)
 ext:     logical_offset:        physical_offset: length:   expected: flags:
   0:        0..      31:   45341441..  45341472:     32:             encoded,shared
   1:       32..      63:   45341456..  45341487:     32:   45341473: encoded,shared
   2:       64..      95:   45341469..  45341500:     32:   45341488: encoded,shared
   3:       96..     115:   45326531..  45326550:     20:   45341501: last,encoded,shared,eof
/tmp/top/SnapsToSend/2024-05-04T14:39:45+10:00_@/usr/lib64/qt5/plugins/bcompare_ext_kde.so: 4 extents found

These extents overlap and different expected start values are reported.

Is this a fault? ( Or a valid set of values that I dont understand?)

Further investigation with all combinations of send options shows:

1) --no-data fails for this file with --compressed-data...

[steve@colt btrfs] $ sudo btrfs send --no-data --compressed-data /tmp/top/SnapsToSend/2024-05-05T12\:28\:40+10\:00_@/ | sudo btrfs receive /mnt/ReceivedSnaps/ -vv 2> receive-nd-cd.log
At subvol /tmp/top/SnapsToSend/2024-05-05T12:28:40+10:00_@/
[steve@colt btrfs] $ tail -n 7 receive-nd-cd.log 
utimes usr/lib/modules/5.15.5-100.fc34.x86_64/modules.builtin.alias.bin
mkfile o4838181-225221-0
rename o4838181-225221-0 -> usr/lib/qt5/plugins/bcompare_ext_kde.so
utimes var/lib/flatpak/repo/objects/c1
set_xattr usr/lib/qt5/plugins/bcompare_ext_kde.so - name=security.selinux data_len=31 data=unconfined_u:object_r:lib_t:s0
clone usr/lib/qt5/plugins/bcompare_ext_kde.so - source=usr/lib64/qt5/plugins/bcompare_ext_kde.so source offset=0 offset=0 length=131072
ERROR: failed to clone extents to usr/lib/qt5/plugins/bcompare_ext_kde.so: Invalid argument

... or without --compressed-data.

[steve@colt btrfs] $ sudo btrfs send --no-data  /tmp/top/SnapsToSend/2024-05-05T12\:28\:40+10\:00_@/ | sudo btrfs receive /mnt/ReceivedSnaps/ -vv 2> receive-nd-ncd.log
At subvol /tmp/top/SnapsToSend/2024-05-05T12:28:40+10:00_@/
[steve@colt btrfs] $ tail -n 7 receive-nd-ncd.log 
utimes usr/lib/modules/5.15.5-100.fc34.x86_64/modules.builtin.alias.bin
mkfile o4838181-225221-0
rename o4838181-225221-0 -> usr/lib/qt5/plugins/bcompare_ext_kde.so
utimes var/lib/flatpak/repo/objects/c1
set_xattr usr/lib/qt5/plugins/bcompare_ext_kde.so - name=security.selinux data_len=31 data=unconfined_u:object_r:lib_t:s0
clone usr/lib/qt5/plugins/bcompare_ext_kde.so - source=usr/lib64/qt5/plugins/bcompare_ext_kde.so source offset=0 offset=0 length=131072
ERROR: failed to clone extents to usr/lib/qt5/plugins/bcompare_ext_kde.so: Invalid argument

Without --no-data, receive processes the sent stream correctly and shares the extents with --compressed-data ...

[steve@colt btrfs] $ sudo btrfs send --compressed-data  /tmp/top/SnapsToSend/2024-05-05T12\:28\:40+10\:00_@/ | sudo btrfs receive /mnt/ReceivedSnaps/ -vv 2> receive-d-cd.log
At subvol /tmp/top/SnapsToSend/2024-05-05T12:28:40+10:00_@/
[steve@colt btrfs] $ tail -n 7 receive-d-cd.log 
>8 ..snip.. >8
BTRFS_IOC_SET_RECEIVED_SUBVOL uuid=4a786cde-fd8d-334a-b356-4c30643e2368, stransid=367210

[steve@colt btrfs] $ filefrag -ev /mnt/ReceivedSnaps/2024-05-05T12\:28\:40+10\:00_@/usr/lib/qt5/plugins/bcompare_ext_kde.so 
Filesystem type is: 9123683e
File size of /mnt/ReceivedSnaps/2024-05-05T12:28:40+10:00_@/usr/lib/qt5/plugins/bcompare_ext_kde.so is 471816 (116 blocks of 4096 bytes)
 ext:     logical_offset:        physical_offset: length:   expected: flags:
   0:        0..      31:    4727066..   4727097:     32:             encoded,shared
   1:       32..      63:    4727081..   4727112:     32:    4727098: encoded,shared
   2:       64..      95:    4727094..   4727125:     32:    4727113: encoded,shared
   3:       96..     115:    4852462..   4852481:     20:    4727126: last,encoded,eof
/mnt/ReceivedSnaps/2024-05-05T12:28:40+10:00_@/usr/lib/qt5/plugins/bcompare_ext_kde.so: 4 extents found

[steve@colt btrfs] $ filefrag -ev /mnt/ReceivedSnaps/2024-05-05T12\:28\:40+10\:00_@/usr/lib64/qt5/plugins/bcompare_ext_kde.so 
Filesystem type is: 9123683e
File size of /mnt/ReceivedSnaps/2024-05-05T12:28:40+10:00_@/usr/lib64/qt5/plugins/bcompare_ext_kde.so is 471816 (116 blocks of 4096 bytes)
 ext:     logical_offset:        physical_offset: length:   expected: flags:
   0:        0..      31:    4727066..   4727097:     32:             encoded,shared
   1:       32..      63:    4727081..   4727112:     32:    4727098: encoded,shared
   2:       64..      95:    4727094..   4727125:     32:    4727113: encoded,shared
   3:       96..     115:    4727103..   4727122:     20:    4727126: last,encoded,eof
/mnt/ReceivedSnaps/2024-05-05T12:28:40+10:00_@/usr/lib64/qt5/plugins/bcompare_ext_kde.so: 4 extents found
[steve@colt btrfs] $

... and builds independant extents without.

[steve@colt btrfs] $ sudo btrfs send  /tmp/top/SnapsToSend/2024-05-05T12\:28\:40+10\:00_@/ | sudo btrfs receive /mnt/ReceivedSnaps/ -vv 2> receive-d-ncd.log
At subvol /tmp/top/SnapsToSend/2024-05-05T12:28:40+10:00_@/
[steve@colt btrfs] $ tail -n 7 receive-d-ncd.log 
>8 ..snip.. >8
BTRFS_IOC_SET_RECEIVED_SUBVOL uuid=4a786cde-fd8d-334a-b356-4c30643e2368, stransid=367210

[steve@colt btrfs] $ filefrag -ev /mnt/ReceivedSnaps/2024-05-05T12\:28\:40+10\:00_@/usr/lib/qt5/plugins/bcompare_ext_kde.so 
Filesystem type is: 9123683e
File size of /mnt/ReceivedSnaps/2024-05-05T12:28:40+10:00_@/usr/lib/qt5/plugins/bcompare_ext_kde.so is 471816 (116 blocks of 4096 bytes)
 ext:     logical_offset:        physical_offset: length:   expected: flags:
   0:        0..      95:    8927627..   8927722:     96:             shared
   1:       96..     115:    8751429..   8751448:     20:    8927723: last,eof
/mnt/ReceivedSnaps/2024-05-05T12:28:40+10:00_@/usr/lib/qt5/plugins/bcompare_ext_kde.so: 2 extents found

[steve@colt btrfs] $ filefrag -ev /mnt/ReceivedSnaps/2024-05-05T12\:28\:40+10\:00_@/usr/lib64/qt5/plugins/bcompare_ext_kde.so 
Filesystem type is: 9123683e
File size of /mnt/ReceivedSnaps/2024-05-05T12:28:40+10:00_@/usr/lib64/qt5/plugins/bcompare_ext_kde.so is 471816 (116 blocks of 4096 bytes)
 ext:     logical_offset:        physical_offset: length:   expected: flags:
   0:        0..     115:    8927627..   8927742:    116:             last,shared,eof
/mnt/ReceivedSnaps/2024-05-05T12:28:40+10:00_@/usr/lib64/qt5/plugins/bcompare_ext_kde.so: 1 extent found

This looks like a bug when receiving metadata of files with shared extents. It assumes it can clone the file when no data is present at the received end.