"btrfs receive" throws "No space left on device" on empty and large enough fs

[Luca Citi]

I have recently installed Kubuntu 16.10 on a btrfs partition of an SSD drive.
I want to take regular snapshots of the filesystem and then back them up to an HDD drive.
I initially used btrbk but ran into a problem that I can also reproduce using vanilla btrfs tool.
The problem is that I get a "No space left on device" when transferring a snapshot taken on the source partition to the destination btrfs partition even though the latter is empty and way larger than needed.

I think the bug may be related to what other have reported here: https://bugzilla.kernel.org/show_bug.cgi?id=74101 .

I report below the steps that I take to reproduce the problem.
In the following /dev/nvme0n1p1 is the source partition and /dev/sda5 is the destination partition.

=== Begin code reproducing the issue ===

$ sudo mkfs.btrfs /dev/sda5
btrfs-progs v4.7.3
See http://btrfs.wiki.kernel.org for more information.

Label: (null)
UUID: bac90738-aaaa-bbbb-cccc-0123456789ab
Node size: 16384
Sector size: 4096
Filesystem size: 45.00GiB
Block group profiles:
  Data: single 8.00MiB
  Metadata: DUP 1.00GiB
  System: DUP 8.00MiB
SSD detected: no
Incompat features: extref, skinny-metadata
Number of devices: 1
Devices:
   ID SIZE PATH
    1 45.00GiB /dev/sda5

$ sudo mount -o subvolid=0 /dev/sda5 /mnt/btr_root_bac

$ mount
[...]
/dev/nvme0n1p1 on / type btrfs (rw,relatime,ssd,space_cache,subvolid=257,subvol=/@)
/dev/nvme0n1p1 on /mnt/btr_root_pool type btrfs (rw,relatime,ssd,space_cache,subvolid=5,subvol=/)
/dev/sda5 on /mnt/btr_root_bac type btrfs (rw,relatime,space_cache,subvolid=5,subvol=/)

$ sudo btrfs fi show
Label: none uuid: 2ef90738-aaaa-bbbb-cccc-0123456789ab
        Total devices 1 FS bytes used 7.59GiB
        devid 1 size 41.91GiB used 16.52GiB path /dev/nvme0n1p1

Label: none uuid: bac90738-aaaa-bbbb-cccc-0123456789ab
        Total devices 1 FS bytes used 112.00KiB
        devid 1 size 45.00GiB used 2.02GiB path /dev/sda5

$ sudo btrfs fi df /mnt/btr_root_pool/
Data, single: total=16.01GiB, used=7.04GiB
System, single: total=4.00MiB, used=16.00KiB
Metadata, single: total=520.00MiB, used=226.89MiB
GlobalReserve, single: total=28.84MiB, used=0.00B

$ sudo btrfs fi df /mnt/btr_root_bac/
Data, single: total=8.00MiB, used=256.00KiB
System, DUP: total=8.00MiB, used=16.00KiB
Metadata, DUP: total=1.00GiB, used=112.00KiB
GlobalReserve, single: total=16.00MiB, used=0.00B

$ sudo btrfs subvolume snapshot -r /mnt/btr_root_pool/@ /mnt/btr_root_pool/@.20170212T1133
Create a readonly snapshot of '/mnt/btr_root_pool/@' in '/mnt/btr_root_pool/@.20170212T1133'

$ sudo btrfs send /mnt/btr_root_pool/@.20170212T1133/ | sudo btrfs receive -vvvv /mnt/btr_root_bac/
[...]
mkfile o85449-15-0
rename o85449-15-0 -> usr/share/icons/oxygen/base/64x64/actions/view-presentation.png
utimes usr/share/icons/oxygen/base/64x64/actions
truncate usr/share/icons/oxygen/base/64x64/actions/view-presentation.png size=4121
chown usr/share/icons/oxygen/base/64x64/actions/view-presentation.png - uid=0, gid=0
chmod usr/share/icons/oxygen/base/64x64/actions/view-presentation.png - mode=0644
utimes usr/share/icons/oxygen/base/64x64/actions/view-presentation.png
mkfile o85450-15-0
rename o85450-15-0 -> usr/share/icons/oxygen/base/64x64/actions/window-duplicate.png
ERROR: rename o85450-15-0 -> usr/share/icons/oxygen/base/64x64/actions/window-duplicate.png failed: No space left on device

$ sudo btrfs fi show
Label: none uuid: 2ef90738-aaaa-bbbb-cccc-0123456789ab
        Total devices 1 FS bytes used 7.26GiB
        devid 1 size 41.91GiB used 16.52GiB path /dev/nvme0n1p1

Label: none uuid: bac90738-aaaa-bbbb-cccc-0123456789ab
        Total devices 1 FS bytes used 2.29GiB
        devid 1 size 45.00GiB used 5.02GiB path /dev/sda5

$ sudo btrfs fi df /mnt/btr_root_bac/
Data, single: total=3.01GiB, used=2.23GiB
System, DUP: total=8.00MiB, used=16.00KiB
Metadata, DUP: total=1.00GiB, used=66.22MiB
GlobalReserve, single: total=16.00MiB, used=0.00B

=== End code reproducing the issue ===

This problem is reproducible and every time I get the same "No space left on device" error although it shows up for different files (i.e., not always when copying window-duplicate.png as in the example above).

Using "btrfs balance" as suggested in some places does not seem to help, probably because the partition is empty and there is nothing to balance.

What seems to help is creating and then removing a large file in the newly created partition, as I do in the following.

=== Begin code working around the issue ===

$ sudo umount /mnt/btr_root_bac

$ sudo dd if=/dev/zero of=/dev/sda5 bs=8M count=10
10+0 records in
10+0 records out
83886080 bytes (84 MB, 80 MiB) copied, 0.461015 s, 182 MB/s

$ sudo mkfs.btrfs /dev/sda5
btrfs-progs v4.7.3
See http://btrfs.wiki.kernel.org for more information.

Label: (null)
UUID: b5bec479-aaaa-bbbb-cccc-0123456789ab
Node size: 16384
Sector size: 4096
Filesystem size: 45.00GiB
Block group profiles:
  Data: single 8.00MiB
  Metadata: DUP 1.00GiB
  System: DUP 8.00MiB
SSD detected: no
Incompat features: extref, skinny-metadata
Number of devices: 1
Devices:
   ID SIZE PATH
    1 45.00GiB /dev/sda5

$ sudo mount -o subvolid=0 /dev/sda5 /mnt/btr_root_bac

$ sudo dd if=/dev/nvme0n1p1 of=/mnt/btr_root_bac/dump status=progress bs=10M count=2000
20898119680 bytes (21 GB, 19 GiB) copied, 93.048 s, 225 MB/s
2000+0 records in
2000+0 records out
20971520000 bytes (21 GB, 20 GiB) copied, 93.4768 s, 224 MB/s

$ sudo rm /mnt/btr_root_bac/dump && sudo btrfs fi df /mnt/btr_root_bac/ && sleep 60 && sudo btrfs fi df /mnt/btr_root_bac/
Data, single: total=20.01GiB, used=5.25MiB
System, DUP: total=8.00MiB, used=16.00KiB
Metadata, DUP: total=1.00GiB, used=240.00KiB
GlobalReserve, single: total=19.95MiB, used=0.00B
Data, single: total=8.00MiB, used=256.00KiB
System, DUP: total=8.00MiB, used=16.00KiB
Metadata, DUP: total=1.00GiB, used=112.00KiB
GlobalReserve, single: total=16.00MiB, used=0.00B

$ sudo btrfs send /mnt/btr_root_pool/@.20170212T1133/ | sudo btrfs receive -vvvv /mnt/btr_root_bac/
[...]
mkfile o2463431-27230-0
rename o2463431-27230-0 -> etc/cups/subscriptions.conf
utimes etc/cups
truncate etc/cups/subscriptions.conf size=670
chown etc/cups/subscriptions.conf - uid=0, gid=7
chmod etc/cups/subscriptions.conf - mode=0640
utimes etc/cups/subscriptions.conf
BTRFS_IOC_SET_RECEIVED_SUBVOL uuid=152b2e73-d062-e84c-a6ec-97d7a633fbf4, stransid=27300

=== End code working around the issue ===

I report the following additional information in case it may be useful to diagnose the problem.

=== Additional information ===

$ lsb_release -rd
Description: Ubuntu 16.10
Release: 16.10

$ apt-cache policy btrfs-progs
btrfs-progs:
  Installed: 4.7.3-1
  Candidate: 4.7.3-1
  Version table:
 *** 4.7.3-1 500
        500 http://gb.archive.ubuntu.com/ubuntu yakkety/main amd64 Packages
        100 /var/lib/dpkg/status

$ uname -a
Linux mypc 4.8.0-37-generic #39-Ubuntu SMP Thu Jan 26 02:27:07 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux

=== End Additional information ===

[Luca Citi (knulp79)]

My work around above (described in the section "code working around the issue") does not consistently work. I was probably just lucky a few times in a row.
I tried several times, with varying delays between creating the huge file and transferring the snapshot but most of them fail and there seem to be no correlation with the delay.

Actually, the same problem arises using rsync so it must not be restricted to btrfs send/receive.

$ rsync -a --stats --one-file-system /mnt/btr_root_pool/@.20170212T1133/ /mnt/btr_root_bac/
rsync: rename "/mnt/btr_root_bac/lib/modules/4.8.0-22-generic/kernel/drivers/staging/comedi/drivers/.fl512.ko.2UT9JI" -> "lib/modules/4.8.0-22-generic/kernel/drivers/staging/comedi/drivers/fl512.ko": No space left on device (28)

Assuming that there may be a problem with btrfs not being able to grow the file system fast enough, I have also tried to limit the transfer rate by using pv:

for RATE in $(seq 2 2 40 | shuf); do
  echo -e "\n\n\n=================\n\nRATE=${RATE}"
  mountpoint -q /mnt/btr_root_bac && umount /mnt/btr_root_bac
  dd if=/dev/zero of=/dev/sda5 bs=8M count=10
  mkfs.btrfs /dev/sda5
  mount -o subvolid=0 /dev/sda5 /mnt/btr_root_bac
  btrfs fi df /mnt/btr_root_bac/
  btrfs send /mnt/btr_root_pool/@.20170212T1133/ | pv --rate-limit ${RATE}m | btrfs receive -vvvv /mnt/btr_root_bac/ 2>&1 | grep -e ERROR -e RECEIVED
  btrfs fi df /mnt/btr_root_bac/
done

The results seem to suggest that the disk operations have a higher chance of suceeding with slower transfer rates:

RATE=2 RECEIVED
RATE=4 RECEIVED
RATE=6 RECEIVED
RATE=8 RECEIVED
RATE=10 RECEIVED
RATE=12 RECEIVED
RATE=14 ERROR
RATE=16 ERROR
RATE=18 ERROR
RATE=20 ERROR
RATE=22 ERROR
RATE=24 ERROR
RATE=26 RECEIVED
RATE=28 ERROR
RATE=30 ERROR
RATE=32 RECEIVED
RATE=34 ERROR
RATE=36 ERROR
RATE=38 ERROR
RATE=40 ERROR

Mounting /dev/sda5 with enospc_debug does not seem to add any useful information to /var/log/syslog.

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.