Hello,
I have a strange problem with btrfs send/receive.
While I can create incremental snaphosts but when I try to restore them
I reproducible get:
> At snapshot 2021-02-20-TEMP
> ERROR: clone: did not find source subvol
I've no "real" problem by that. Just want to report the issue so someone
with more btrfs knowledge can dig into what went wrong here. After all
that looks like a bug...
So I plan to keep it as it is for some more days and then play around to
get incremental send/receive working again.
Here the procedure how I can reproduce the issue:
At start I have the following snapshots in the root of the affected file
system. (Subvol "active is mounted as / and the btrfs root on
/mnt/backup/backupdev):
active <- the live RW filesystem
2021-02-14 <- a RO snapshot of the above from some days ago
And these steps reproducible are failing on btrfs recive:
1) create a new RO snapshot of active
# btrfs sub snap -r active/ 2021-02-20-TEMP
Create a readonly snapshot of 'active/' in './2021-02-20-TEMP'
2) btrfs send with 2021-02-14 as parent into test2
# btrfs send -p 2021-02-14 2021-02-20-TEMP -f test2
At subvol 2021-02-20-TEMP
3) remove the snapshot 2021-02-20-TEMP
# btrfs sub del 2021-02-20-TEMP
Delete subvolume (no-commit): '/mnt/backup/backupdev/2021-02-20-TEMP'
4) and try to import it again from test2
# btrfs receive -f test2 .
At snapshot 2021-02-20-TEMP
ERROR: clone: did not find source subvol
The same procedure is working for another btrfs filesystem on the same
system.
The system is an Ubuntu 20.04 (kernel 5.4.0-65-generic, btrfs-progs v5.4.1).
And here some more information which may be useful:
# btrfs sub show active
active
Name: active
UUID: a2ff485b-9f8f-2543-ad03-dc7c917e143b
Parent UUID: 6da3d5ab-4d9f-4805-b77e-0eab8ce2abc8
Received UUID: -
Creation time: 2020-11-08 13:58:23 +0100
Subvolume ID: 264
Generation: 206432
Gen at creation: 167
Parent ID: 5
Top level ID: 5
Flags: -
Snapshot(s):
# btrfs sub show 2021-02-14
2021-02-14
Name: 2021-02-14
UUID: d31d553f-0917-3c48-b65c-ec51fd0c6d89
Parent UUID: a2ff485b-9f8f-2543-ad03-dc7c917e143b
Received UUID: -
Creation time: 2021-02-14 21:46:26 +0100
Subvolume ID: 358
Generation: 206378
Gen at creation: 195056
Parent ID: 5
Top level ID: 5
Flags: readonly
Snapshot(s):
# btrfs sub show 2021-02-20-TEMP
2021-02-20-TEMP
Name: 2021-02-20-TEMP
UUID: 120113e6-f83c-b240-ba27-259be4c92ea7
Parent UUID: a2ff485b-9f8f-2543-ad03-dc7c917e143b
Received UUID: -
Creation time: 2021-02-20 18:06:29 +0100
Subvolume ID: 375
Generation: 206770
Gen at creation: 206770
Parent ID: 5
Top level ID: 5
Flags: readonly
Snapshot(s):
# time btrfs receive -v -f test2 .
receiving snapshot 2021-02-20-TEMP
uuid=120113e6-f83c-b240-ba27-259be4c92ea7, ctransid=206769
parent_uuid=d31d553f-0917-3c48-b65c-ec51fd0c6d89, parent_ctransid=195056
write var/log/lastlog - offset=290816 length=4096
write var/log/wtmp - offset=122880 length=4096
write var/log/wtmp - offset=126976 length=4096
write var/log/wtmp - offset=131072 length=4096
write var/log/wtmp - offset=135168 length=384
write boot/grub/grubenv - offset=0 length=1024
write var/lib/systemd/random-seed - offset=0 length=512
write var/log/cloud-init.log - offset=1138688 length=49152
write var/log/cloud-init.log - offset=1187840 length=11555
write var/log/cloud-init-output.log - offset=53248 length=5329
write var/lib/cloud/instances/iid-datasource-none/datasource - offset=0
length=31
write var/lib/cloud/data/previous-datasource - offset=0 length=31
write var/lib/cloud/data/instance-id - offset=0 length=20
write var/lib/cloud/data/previous-instance-id - offset=0 length=20
write var/lib/cloud/instances/iid-datasource-none/obj.pkl - offset=0
length=8107
write var/lib/cloud/instances/iid-datasource-none/user-data.txt -
offset=0 length=356
write var/lib/cloud/instances/iid-datasource-none/user-data.txt.i -
offset=0 length=661
write var/lib/cloud/instances/iid-datasource-none/vendor-data.txt.i -
offset=0 length=308
write var/lib/cloud/instances/iid-datasource-none/cloud-config.txt -
offset=0 length=435
write var/cache/motd-news - offset=0 length=184
<removed 10200 lines>
write var/lib/mysql/mysql/innodb_index_stats.ibd - offset=393216
length=16384
write var/lib/mysql/mysql/innodb_index_stats.ibd - offset=409600
length=16384
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=0 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=8192 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=16384 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=24576 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=40960 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=49152 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=114688 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=155648 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=180224 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=212992 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=229376 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=253952 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=278528 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=294912 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=319488 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=385024 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=483328 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=516096 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=720896 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=729088 length=8192
write var/lib/mysql/nextcloud/oc_activity.ibd - offset=737280 length=8192
ERROR: clone: did not find source subvol
At snapshot 2021-02-20-TEMP
real 0m0.741s
user 0m0.246s
sys 0m0.127s
Noteworthy here is, that var/lib/mysql/ has set "chattr +C" set:
# lsattr 2021-02-20-TEMP/var/lib/mysql
---------------C---- 2021-02-20-TEMP/var/lib/mysql/aria_log.00000001
---------------C---- 2021-02-20-TEMP/var/lib/mysql/aria_log_control
---------------C---- 2021-02-20-TEMP/var/lib/mysql/debian-10.3.flag
---------------C---- 2021-02-20-TEMP/var/lib/mysql/ib_logfile0
---------------C---- 2021-02-20-TEMP/var/lib/mysql/ib_logfile1
---------------C---- 2021-02-20-TEMP/var/lib/mysql/ibdata1
---------------C---- 2021-02-20-TEMP/var/lib/mysql/multi-master.info
---------------C---- 2021-02-20-TEMP/var/lib/mysql/mysql_upgrade_info
---------------C---- 2021-02-20-TEMP/var/lib/mysql/mysql
---------------C---- 2021-02-20-TEMP/var/lib/mysql/nextcloud
---------------C---- 2021-02-20-TEMP/var/lib/mysql/performance_schema
---------------C---- 2021-02-20-TEMP/var/lib/mysql/roundcube
---------------C---- 2021-02-20-TEMP/var/lib/mysql/wordpress
---------------C---- 2021-02-20-TEMP/var/lib/mysql/mailserver
---------------C---- 2021-02-20-TEMP/var/lib/mysql/ib_buffer_pool
---------------C---- 2021-02-20-TEMP/var/lib/mysql/tc.log
---------------C---- 2021-02-20-TEMP/var/lib/mysql/ibtmp1