ENOSPC during snapshot creation

[kdave]

The base workload is git checkout of random commits. In parallel there's read-only snapshot every second. The overall state of the space in the filesystem is below limits so a metadata operation should succeed. Stats saved after the error happens: there's some remaining metadata space (so snapshot should work), there is usable data space, global reserve is small but should be large enough(?). The whole disk is 2G, maybe the global reserve is not scaled properly(?).

# ./btrfs fi df /root/btrfs-progs/mnt
Data, single: total=768.00MiB, used=183.67MiB, zone_unusable=354.12MiB
System, single: total=256.00MiB, used=16.00KiB, zone_unusable=1.44MiB
Metadata, single: total=512.00MiB, used=77.31MiB, zone_unusable=434.69MiB
GlobalReserve, single: total=3.25MiB, used=0.00B

# blkzone report /dev/nullb0
  start: 0x000000000, len 0x080000, wptr 0x0035b8 reset:0 non-seq:0, zcond: 2(oi) [type: 2(SEQ_WRITE_REQUIRED)]
  start: 0x000080000, len 0x080000, wptr 0x000000 reset:0 non-seq:0, zcond: 1(em) [type: 2(SEQ_WRITE_REQUIRED)]
  start: 0x000100000, len 0x080000, wptr 0x000ba0 reset:0 non-seq:0, zcond: 2(oi) [type: 2(SEQ_WRITE_REQUIRED)]
  start: 0x000180000, len 0x080000, wptr 0x07f520 reset:0 non-seq:0, zcond: 2(oi) [type: 2(SEQ_WRITE_REQUIRED)]
  start: 0x000200000, len 0x080000, wptr 0x080000 reset:0 non-seq:0, zcond:14(fu) [type: 2(SEQ_WRITE_REQUIRED)]
  start: 0x000280000, len 0x080000, wptr 0x080000 reset:0 non-seq:0, zcond:14(fu) [type: 2(SEQ_WRITE_REQUIRED)]
  start: 0x000300000, len 0x080000, wptr 0x080000 reset:0 non-seq:0, zcond:14(fu) [type: 2(SEQ_WRITE_REQUIRED)]
  start: 0x000380000, len 0x080000, wptr 0x00d3b8 reset:0 non-seq:0, zcond: 2(oi) [type: 2(SEQ_WRITE_REQUIRED)]

[74047.633693] BTRFS info (device nullb0): reclaiming chunk 10737418240 with 0% used
[74047.661820] BTRFS info (device nullb0): relocating block group 10737418240 flags data
[74047.887664] BTRFS info (device nullb0): found 35 extents, stage: move data extents
[74048.064077] BTRFS info (device nullb0): found 35 extents, stage: update data pointers
[74109.073706] BTRFS info (device nullb0): reclaiming chunk 11005853696 with 0% used
[74109.082466] BTRFS info (device nullb0): relocating block group 11005853696 flags data
[74109.197620] BTRFS info (device nullb0): found 34 extents, stage: move data extents
[74109.274486] BTRFS info (device nullb0): found 34 extents, stage: update data pointers
[74166.417619] BTRFS info (device nullb0): reclaiming chunk 11542724608 with 0% used
[74166.426843] BTRFS info (device nullb0): relocating block group 11542724608 flags data
[74166.660917] BTRFS info (device nullb0): found 38 extents, stage: move data extents
[74166.811428] BTRFS info (device nullb0): found 38 extents, stage: update data pointers
[74197.137961] BTRFS info (device nullb0): reclaiming chunk 11811160064 with 0% used
[74197.146631] BTRFS info (device nullb0): relocating block group 11811160064 flags data
[74197.336471] BTRFS info (device nullb0): found 39 extents, stage: move data extents
[74197.434796] BTRFS info (device nullb0): found 39 extents, stage: update data pointers
[74258.577631] BTRFS info (device nullb0): reclaiming chunk 12079595520 with 0% used
[74258.629802] BTRFS info (device nullb0): relocating block group 12079595520 flags data
[74258.809853] BTRFS info (device nullb0): found 40 extents, stage: move data extents
[74258.927464] BTRFS info (device nullb0): found 40 extents, stage: update data pointers
[74286.790407] BTRFS warning (device nullb0): insert uuid item failed -28 (0x40a1433e0abd778c, 0x85d32a11b39dbe9d) type 251!
[74286.801965] ------------[ cut here ]------------
[74286.806761] BTRFS: Transaction aborted (error -28)
[74286.811904] WARNING: CPU: 3 PID: 3070 at fs/btrfs/transaction.c:1776 create_pending_snapshot+0x96d/0xb90 [btrfs]
[74286.812104] Modules linked in: blake2b_generic btrfs null_blk loop nfs lockd grace sunrpc fscache i2c_algo_bit drm_ttm_helper ttm netfs drm_kms_helper af_packet syscopyarea sysfillrect bridge sysimgblt fb_sys_fops drm stp llc tg3 tpm_infineon tpm_tis tpm_tis_core tpm libcrc32c iscsi_ibft xor zstd_decompress iscsi_boot_sysfs zstd_compress libphy xxhash raid6_pq i2c_piix4 mptctl acpi_cpufreq button k10temp serio_raw ext4 mbcache jbd2 ohci_pci mptsas scsi_transport_sas ehci_pci ata_generic ohci_hcd mptscsih ehci_hcd mptbase usbcore sata_svw pata_serverworks sg scsi_dh_rdac scsi_dh_emc scsi_dh_alua [last unloaded: btrfs]
[74286.878686] CPU: 3 PID: 3070 Comm: btrfs Tainted: G        W         5.13.0-rc6-git+ #775
[74286.878694] Hardware name: empty empty/S3993, BIOS PAQEX0-3 02/24/2008
[74286.878699] RIP: 0010:create_pending_snapshot+0x96d/0xb90 [btrfs]
[74286.900124] Code: 08 1c 00 00 03 72 25 41 83 ff fb 0f 84 9f e3 0b 00 41 83 ff e2 0f 84 95 e3 0b 00 44 89 fe 48 c7 c7 68 f2 c8 c0 e8 26 b9 d4 d9 <0f> 0b 44 89 f9 ba f0 06 00 00 48 c7 c6 10 df c7 c0 4c 89 e7 e8 a5
[74286.900130] RSP: 0018:ffffb4e98b1afba0 EFLAGS: 00010286
[74286.900138] RAX: 0000000000000000 RBX: ffff93692edbb500 RCX: 0000000000000000
[74286.900142] RDX: ffff936a275ea2c0 RSI: ffff936a275d9970 RDI: ffff936a275d9970
[74286.900146] RBP: ffffb4e98b1afc70 R08: 0000000000000001 R09: 0000000000000001
[74286.900150] R10: 0000000000000000 R11: 0000000000000000 R12: ffff936834c341c0
[74286.900153] R13: ffff936921817a00 R14: ffff93691971bd48 R15: 00000000ffffffe4
[74286.900158] FS:  00007f8b131e08c0(0000) GS:ffff936a27400000(0000) knlGS:0000000000000000
[74286.900162] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[74286.900166] CR2: 00007f8b131f7000 CR3: 0000000134d7b000 CR4: 00000000000006e0
[74286.900171] Call Trace:
[74286.900227]  ? create_pending_snapshots+0xaa/0xd0 [btrfs]
[74286.900327]  create_pending_snapshots+0xaa/0xd0 [btrfs]
[74286.996268]  btrfs_commit_transaction+0x43b/0xb10 [btrfs]
[74287.001920]  ? __lock_release+0x179/0x2c0
[74287.001937]  ? create_snapshot+0x1f0/0x2b0 [btrfs]
[74287.002043]  create_snapshot+0x1f8/0x2b0 [btrfs]
[74287.002150]  btrfs_mksubvol+0x103/0x190 [btrfs]
[74287.002254]  btrfs_mksnapshot+0x7d/0xb0 [btrfs]
[74287.025564]  __btrfs_ioctl_snap_create+0x176/0x180 [btrfs]
[74287.025685]  btrfs_ioctl_snap_create_v2+0xb3/0x130 [btrfs]
[74287.025800]  btrfs_ioctl+0x630/0xae0 [btrfs]
[74287.025921]  __x64_sys_ioctl+0x83/0xa0
[74287.025945]  do_syscall_64+0x3f/0xb0
[74287.025965]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[74287.025974] RIP: 0033:0x7f8b12269327
[74287.025981] Code: 00 00 00 48 8b 05 61 9b 2b 00 64 c7 00 26 00 00 00 48 c7 c0 ff ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 31 9b 2b 00 f7 d8 64 89 01 48
[74287.025986] RSP: 002b:00007ffe66ac90b8 EFLAGS: 00000206 ORIG_RAX: 0000000000000010
[74287.025993] RAX: ffffffffffffffda RBX: 000000000000000b RCX: 00007f8b12269327
[74287.025997] RDX: 00007ffe66ac9100 RSI: 0000000050009417 RDI: 000000000000000a
[74287.026001] RBP: 0000000001c90010 R08: 0000000000000000 R09: 000000000000000a
[74287.026004] R10: 000000000fa99fa0 R11: 0000000000000206 R12: 00007ffe66acb852
[74287.026008] R13: 00007ffe66ac9100 R14: 0000000000000001 R15: 0000000001c90030
[74287.026052] irq event stamp: 12815
[74287.026055] hardirqs last  enabled at (12821): [<ffffffff9a10f475>] console_trylock_spinning+0x185/0x1a0
[74287.026063] hardirqs last disabled at (12826): [<ffffffff9a10f44c>] console_trylock_spinning+0x15c/0x1a0
[74287.026068] softirqs last  enabled at (12722): [<ffffffff9ac00307>] __do_softirq+0x307/0x50f
[74287.026075] softirqs last disabled at (12717): [<ffffffff9a08ad56>] irq_exit_rcu+0xb6/0xf0
[74287.026082] ---[ end trace df041bacfc0d9e7d ]---
[74287.026208] BTRFS: error (device nullb0) in create_pending_snapshot:1776: errno=-28 No space left
[74287.026276] BTRFS info (device nullb0): forced readonly
[74287.026402] BTRFS warning (device nullb0): Skipping commit of aborted transaction.
[74287.026461] BTRFS: error (device nullb0) in cleanup_transaction:1954: errno=-28 No space left