Allocating free space is not triggered during balance

[mikhailnov]

I have met the same situation recently on 2 different machines with BTRFS, both with Ubuntu kernel 5.3.0 and btrfs-progs 5.4.
df -h shows a lot of free space, but btrfs balance says that there is not enough free space: ERROR: error during balancing 'sda2': No space left on device (in dmesg: balance: ended with status: -28).
The first thought here is that there is a misbalance of space allocated for metadata and data, but no, most of space on the device is just not allocated, example:

root@pay2:/tmp# btrfs filesystem usage /
Overall:
    Device size:		 182.76GiB
    Device allocated:		 116.03GiB
    Device unallocated:		  66.73GiB
    Device missing:		     0.00B
    Used:			 110.90GiB
    Free (estimated):		  67.69GiB	(min: 67.69GiB)
    Data ratio:			      1.00
    Metadata ratio:		      1.00
    Global reserve:		 512.00MiB	(used: 0.00B)

Data,single: Size:108.00GiB, Used:107.04GiB (99.11%)
   /dev/sda2	 108.00GiB

Metadata,single: Size:8.00GiB, Used:3.86GiB (48.30%)
   /dev/sda2	   8.00GiB

System,single: Size:32.00MiB, Used:16.00KiB (0.05%)
   /dev/sda2	  32.00MiB

Unallocated:
   /dev/sda2	  66.73GiB

Here the problem is: Data,single: Size:108.00GiB, Used:107.04GiB (99.11%),<1GB of free allocated space is not enough for balancing.

Running dd if=/dev/urandom of=/root/testfile bs=4MB status=progress triggers allocating space, but after I delete /root/testfile a large part of space quickly becomes not allocated again. Here it is not clear how to perform a good btrfs balance.

I use btrfsmaintenance for all mount points (auto) with default systemd timers. Regular balance by btrfsmaintenance did not help to avoid fake lack of free space on both machines.

This situation - inability to balance properly - decreases performance, especially on HDD. The user of that machine with HDD complained that XFCE desktop started up too slowly, while it started up much quicker some time ago.

P.S. I wrote that Load Average sometimes increses dramatically when Chromium is running on BTRFS and is trying to read/write from disk - https://bugzilla.kernel.org/show_bug.cgi?id=196729, maybe this misbalance was at least one of the reasons.

[mikhailnov]

I installed vanilla kernel 5.4.6, the problem is the same, balance cannot be done.

[mikhailnov]

and the same is with kernel 5.5-rc4, there is nothing newer in fs/btrfs

[mikhailnov]

root@pay2:~# for THRESH in `seq 0 5 60`; do btrfs balance start -dusage=${THRESH} -musage=${THRESH} / ; done
Done, had to relocate 0 out of 115 chunks
Done, had to relocate 2 out of 115 chunks
Done, had to relocate 1 out of 114 chunks
Done, had to relocate 1 out of 114 chunks
Done, had to relocate 1 out of 114 chunks
Done, had to relocate 1 out of 114 chunks
Done, had to relocate 1 out of 114 chunks
Done, had to relocate 1 out of 114 chunks
Done, had to relocate 1 out of 114 chunks
Done, had to relocate 1 out of 114 chunks
Done, had to relocate 1 out of 114 chunks
Done, had to relocate 1 out of 114 chunks
Segmentation fault

dmesg:

[Mon Dec 30 22:21:57 2019] BTRFS info (device sda2): found 2495 extents
[Mon Dec 30 22:21:57 2019] BTRFS info (device sda2): found 2495 extents
<...>
[Mon Dec 30 22:21:57 2019] ------------[ cut here ]------------
[Mon Dec 30 22:21:57 2019] kernel BUG at fs/btrfs/relocation.c:4685!
[Mon Dec 30 22:21:57 2019] invalid opcode: 0000 [#1] SMP NOPTI
[Mon Dec 30 22:21:57 2019] CPU: 0 PID: 79996 Comm: btrfs Tainted: G        W  OE     5.5.0-050500rc4-generic #201912291930
[Mon Dec 30 22:21:57 2019] Hardware name: ASUS All Series/AM1I-A, BIOS 0801 03/10/2016
[Mon Dec 30 22:21:57 2019] RIP: 0010:btrfs_reloc_cow_block+0x329/0x350 [btrfs]
[Mon Dec 30 22:21:57 2019] Code: ff 48 8b 5b 10 48 85 db 0f 84 aa fd ff ff 48 3b 4b 18 72 ed 0f 86 7f fd ff ff 48 8b 5b 08 eb e5 48 3b 56 20 0f 84 bb fe ff ff <0f> 0b 49 8b 94 24 df 01 00 00 e9 e6 fd ff ff 0f 0b 31 c9 e9 8e fe
[Mon Dec 30 22:21:57 2019] RSP: 0018:ffffb44dc37db758 EFLAGS: 00010206
[Mon Dec 30 22:21:57 2019] RAX: 0000000000000001 RBX: 0000000000000001 RCX: 0000000000000001
[Mon Dec 30 22:21:57 2019] RDX: 00000122e4218000 RSI: ffff94f19ea7c280 RDI: ffff94f2305876e8
[Mon Dec 30 22:21:57 2019] RBP: ffffb44dc37db7a0 R08: ffff94f0939617b8 R09: ffffffffc02a7c00
[Mon Dec 30 22:21:57 2019] R10: ffff94f236e62758 R11: 0000000000000001 R12: ffff94f1f83da800
[Mon Dec 30 22:21:57 2019] R13: ffff94f1cd492800 R14: ffff94f09ff21de8 R15: ffff94f2305876e8
[Mon Dec 30 22:21:57 2019] FS:  00007fc12bb468c0(0000) GS:ffff94f239400000(0000) knlGS:0000000000000000
[Mon Dec 30 22:21:57 2019] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[Mon Dec 30 22:21:57 2019] CR2: 00007f619f7c0000 CR3: 00000000340da000 CR4: 00000000000406f0
[Mon Dec 30 22:21:57 2019] Call Trace:
[Mon Dec 30 22:21:57 2019]  __btrfs_cow_block+0x344/0x4f0 [btrfs]
[Mon Dec 30 22:21:57 2019]  btrfs_cow_block+0xfa/0x1a0 [btrfs]
[Mon Dec 30 22:21:57 2019]  btrfs_search_slot+0x504/0x980 [btrfs]
[Mon Dec 30 22:21:57 2019]  do_relocation+0x4a0/0x640 [btrfs]
[Mon Dec 30 22:21:57 2019]  ? build_backref_tree+0x1069/0x1140 [btrfs]
[Mon Dec 30 22:21:57 2019]  ? btrfs_block_rsv_refill+0x37/0xa0 [btrfs]
[Mon Dec 30 22:21:57 2019]  relocate_tree_blocks+0x4f5/0x630 [btrfs]
[Mon Dec 30 22:21:57 2019]  ? add_data_references+0x254/0x260 [btrfs]
[Mon Dec 30 22:21:57 2019]  relocate_block_group+0x224/0x5f0 [btrfs]
[Mon Dec 30 22:21:57 2019]  btrfs_relocate_block_group+0x169/0x310 [btrfs]
[Mon Dec 30 22:21:57 2019]  btrfs_relocate_chunk+0x2a/0x90 [btrfs]
[Mon Dec 30 22:21:57 2019]  __btrfs_balance+0x409/0xa80 [btrfs]
[Mon Dec 30 22:21:57 2019]  btrfs_balance+0x396/0x520 [btrfs]
[Mon Dec 30 22:21:57 2019]  btrfs_ioctl_balance+0x2c1/0x380 [btrfs]
[Mon Dec 30 22:21:57 2019]  btrfs_ioctl+0x836/0x20d0 [btrfs]
[Mon Dec 30 22:21:57 2019]  ? __handle_mm_fault+0x810/0x850
[Mon Dec 30 22:21:57 2019]  ? arch_get_unmapped_area_topdown+0x57/0x200
[Mon Dec 30 22:21:57 2019]  do_vfs_ioctl+0x458/0x6d0
[Mon Dec 30 22:21:57 2019]  ? do_vfs_ioctl+0x458/0x6d0
[Mon Dec 30 22:21:57 2019]  ? do_user_addr_fault+0x216/0x450
[Mon Dec 30 22:21:57 2019]  ksys_ioctl+0x67/0x90
[Mon Dec 30 22:21:57 2019]  __x64_sys_ioctl+0x1a/0x20
[Mon Dec 30 22:21:57 2019]  do_syscall_64+0x57/0x1b0
[Mon Dec 30 22:21:57 2019]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Mon Dec 30 22:21:57 2019] RIP: 0033:0x7fc12bc6067b
[Mon Dec 30 22:21:57 2019] Code: 0f 1e fa 48 8b 05 15 28 0d 00 64 c7 00 26 00 00 00 48 c7 c0 ff ff ff ff c3 66 0f 1f 44 00 00 f3 0f 1e fa b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d e5 27 0d 00 f7 d8 64 89 01 48
[Mon Dec 30 22:21:57 2019] RSP: 002b:00007fffc4d4a068 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[Mon Dec 30 22:21:57 2019] RAX: ffffffffffffffda RBX: 00007fffc4d4a108 RCX: 00007fc12bc6067b
[Mon Dec 30 22:21:57 2019] RDX: 00007fffc4d4a108 RSI: 00000000c4009420 RDI: 0000000000000003
[Mon Dec 30 22:21:57 2019] RBP: 0000000000000003 R08: 000055fef5b0f2a0 R09: 000000000000007c
[Mon Dec 30 22:21:57 2019] R10: 00007fc12bd33be0 R11: 0000000000000246 R12: 0000000000000001
[Mon Dec 30 22:21:57 2019] R13: 0000000000000000 R14: 00007fffc4d4bd03 R15: 0000000000000001
[Mon Dec 30 22:21:57 2019] Modules linked in: xt_conntrack ipt_REJECT nf_reject_ipv4 ip6table_mangle ip6table_nat nf_tables nfnetlink ip6table_filter ip6_tables nfsv3 nfs_acl iptable_mangle xt_CHECKSUM iptable_nat xt_MASQUERADE nf_nat nf_conntrack rpcsec_gss_krb5 nf_defrag_ipv6 nf_defrag_ipv4 auth_rpcgss nfsv4 xt_tcpudp nfs lockd grace fscache bridge stp llc iptable_filter bpfilter bluetooth ecdh_generic ecc binfmt_misc nls_iso8859_1 amdgpu amd_iommu_v2 gpu_sched amd_freq_sensitivity edac_mce_amd kvm_amd ccp kvm irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel aesni_intel crypto_simd snd_usb_audio cryptd snd_hda_codec_realtek glue_helper snd_hda_codec_generic ledtrig_audio snd_hda_codec_hdmi snd_hda_intel snd_usbmidi_lib snd_intel_dspcfg snd_seq_midi snd_seq_midi_event snd_hda_codec eeepc_wmi uvcvideo snd_hda_core videobuf2_vmalloc asus_wmi radeon sparse_keymap serio_raw videobuf2_memops snd_hwdep snd_rawmidi snd_seq video wmi_bmof input_leds joydev videobuf2_v4l2 fam15h_power snd_pcm
[Mon Dec 30 22:21:57 2019]  videobuf2_common ttm snd_seq_device k10temp drm_kms_helper snd_timer drm snd i2c_algo_bit fb_sys_fops syscopyarea soundcore sysfillrect sysimgblt mac_hid sch_fq_codel it87 hwmon_vid videodev mc parport_pc ppdev lp parport sunrpc ip_tables x_tables autofs4 btrfs blake2b_generic zstd_compress raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multipath linear dm_mirror dm_region_hash dm_log hid_generic usbhid hid uas usb_storage psmouse r8169 ahci libahci i2c_piix4 wmi realtek
[Mon Dec 30 22:21:57 2019] ---[ end trace 6a71f0162c5e398c ]---
[Mon Dec 30 22:21:57 2019] RIP: 0010:btrfs_reloc_cow_block+0x329/0x350 [btrfs]
[Mon Dec 30 22:21:57 2019] Code: ff 48 8b 5b 10 48 85 db 0f 84 aa fd ff ff 48 3b 4b 18 72 ed 0f 86 7f fd ff ff 48 8b 5b 08 eb e5 48 3b 56 20 0f 84 bb fe ff ff <0f> 0b 49 8b 94 24 df 01 00 00 e9 e6 fd ff ff 0f 0b 31 c9 e9 8e fe
[Mon Dec 30 22:21:57 2019] RSP: 0018:ffffb44dc37db758 EFLAGS: 00010206
[Mon Dec 30 22:21:57 2019] RAX: 0000000000000001 RBX: 0000000000000001 RCX: 0000000000000001
[Mon Dec 30 22:21:57 2019] RDX: 00000122e4218000 RSI: ffff94f19ea7c280 RDI: ffff94f2305876e8
[Mon Dec 30 22:21:57 2019] RBP: ffffb44dc37db7a0 R08: ffff94f0939617b8 R09: ffffffffc02a7c00
[Mon Dec 30 22:21:57 2019] R10: ffff94f236e62758 R11: 0000000000000001 R12: ffff94f1f83da800
[Mon Dec 30 22:21:57 2019] R13: ffff94f1cd492800 R14: ffff94f09ff21de8 R15: ffff94f2305876e8
[Mon Dec 30 22:21:57 2019] FS:  00007fc12bb468c0(0000) GS:ffff94f239400000(0000) knlGS:0000000000000000
[Mon Dec 30 22:21:57 2019] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[Mon Dec 30 22:21:57 2019] CR2: 00007f619f7c0000 CR3: 00000000340da000 CR4: 00000000000406f0

[mikhailnov]

fsck of that filesystem:

root@HP-Notebook-Linux:~# btrfs check --repair /dev/sda2
enabling repair mode
WARNING:

	Do not use --repair unless you are advised to do so by a developer
	or an experienced user, and then only after having accepted that no
	fsck can successfully repair all types of filesystem corruption. Eg.
	some software or hardware bugs can fatally damage a volume.
	The operation will start in 10 seconds.
	Use Ctrl-C to stop it.
10 9 8 7 6 5 4 3 2 1
Starting repair.
Opening filesystem to check...
Checking filesystem on /dev/sda2
UUID: 745b0c43-6a82-4bce-9821-7f5dd88a9246
[1/7] checking root items
Fixed 0 roots.
[2/7] checking extents
No device size related problem found
[3/7] checking free space cache
cache and super generation don't match, space cache will be invalidated
[4/7] checking fs roots
root 358 inode 8037729 errors 1040, bad file extent, some csum missing
root 358 inode 8037859 errors 1040, bad file extent, some csum missing
root 358 inode 8038482 errors 1040, bad file extent, some csum missing
root 358 inode 8038754 errors 1040, bad file extent, some csum missing
root 358 inode 8111001 errors 1040, bad file extent, some csum missing
root 358 inode 8111012 errors 1040, bad file extent, some csum missing
root 358 inode 8111013 errors 1040, bad file extent, some csum missing
root 358 inode 8260866 errors 1040, bad file extent, some csum missing
root 358 inode 8260867 errors 1040, bad file extent, some csum missing
root 2959 inode 8037729 errors 1040, bad file extent, some csum missing
root 2959 inode 8037859 errors 1040, bad file extent, some csum missing
root 2959 inode 8038482 errors 1040, bad file extent, some csum missing
root 2959 inode 8038754 errors 1040, bad file extent, some csum missing
root 2959 inode 8111001 errors 1040, bad file extent, some csum missing
root 2959 inode 8111012 errors 1040, bad file extent, some csum missing
root 2959 inode 8111013 errors 1040, bad file extent, some csum missing
root 2959 inode 8260866 errors 1040, bad file extent, some csum missing
root 2959 inode 8260867 errors 1040, bad file extent, some csum missing
ERROR: errors found in fs roots
found 122872688640 bytes used, error(s) found
total csum bytes: 111673716
total tree bytes: 5888360448
total fs tree bytes: 5527404544
total extent tree bytes: 225869824
btree space waste bytes: 1347727257
file data blocks allocated: 283436072960
 referenced 258824556544

[ernsteiswuerfel]

Nice - this looks similar to the issue on my amd64 box during balancing.

Reported it to kernel bugzilla some time ago.

[marcosps]

@mikhailnov a patch was posted in the ML related to this issue. Let's hope it gets merged soon in the next kernel, and maybe gets backported.

If you desire, you can apply the patch and check if this fixes your issue, and please say here if it worked for you. It's good to have people who can test fixes. Thanks!

[fdmanana]

Note: the patch is meant to fix the crash during balance only. I.e. the BUG_ON() hit at

kernel BUG at fs/btrfs/relocation.c:4685!

It doesn't address any ENOSPC problems. Just to be clear. Since in this issue there are 2 (at least) different problems reported.

Thanks.

[ernsteiswuerfel]

Just tested the patch applied on top of 5.5.3. My balancing issue is gone now, thanks!

I got ENOSPC reported one time (full balance), but not the 2nd time I did a balance on the same partition (also full balance). But dit not trigger any bug in the process.

[fdmanana]

Just tested the patch applied on top of 5.5.3. My balancing issue is gone now, thanks!

I got ENOSPC reported one time (full balance), but not the 2nd time I did a balance on the same partition (also full balance). But dit not trigger any bug in the process.

Great!
Btw, if you are subscribed to the btrfs mailing list, you can add:

Tested-by: Your Name your@email.whatever

I didn't add a "Reported-by:" tag since I didn't have your name and email address.

Anyway, it's optional of course.
Thanks for testing.

[marcosps]

@mikhailnov @fdmanana @kdave since the patch was merged into next, can we close this bug?