btrfs kernel bug at relocation.c

[Ken Sharp]

I've just tried to do a btrfs-balance of /home. This failed. Badly. With a segfault. dmesg showed a specific message but that has long gone. Because this messed up my filesystem it was not logged. I won't be trying this again!

Furthermore my free space has increased by 1 GB. As I doubt the balance managed to achieve such an amazing feat in the fraction of a second it was running, I must now assume that data has been lost, and I'll have the joy of trying to find out what, exactly.

What was preserved:

Oct 27 11:27:34 kernel: [15526.726385] WARNING: CPU: 6 PID: 14722 at /build/linux-hwe-zHO4ZF/linux-hwe-5.0.0/fs/btrfs/extent-tree.c:69 find_free_extent+0xe79/0x1050 [btrfs]
Oct 27 11:27:34 kernel: [15526.726385] Modules linked in: bluetooth ecdh_generic msr xfs jfs tcp_diag inet_diag veth xt_CHECKSUM iptable_mangle xt_tcpudp ipt_MASQUERADE xt_comment iptable_nat nf_nat_ipv4 nf_nat bridge stp llc ip6t_REJECT nf_reject_ipv6 xt_NFLOG xt_u32 ipt_REJECT nf_reject_ipv4 xt_conntrack xt_connmark nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 nfnetlink_log nfnetlink nls_utf8 udf crc_itu_t pci_stub vboxpci(OE) vboxnetadp(OE) vboxnetflt(OE) vboxdrv(OE) snd_hda_codec_hdmi ip6table_filter ip6_tables iptable_filter bpfilter binfmt_misc intel_rapl sb_edac x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel aesni_intel aes_x86_64 crypto_simd cryptd glue_helper snd_hda_codec_realtek snd_hda_codec_generic ledtrig_audio wmi_bmof snd_hda_intel snd_hda_codec snd_hda_core snd_hwdep snd_pcm snd_seq_midi snd_seq_midi_event snd_rawmidi uas usb_storage intel_cstate snd_seq isci psmouse snd_seq_device intel_rapl_perf serio_raw snd_timer e1000e
Oct 27 11:27:34 kernel: [15526.726418] libsas mei_me scsi_transport_sas snd mei lpc_ich pata_acpi soundcore ioatdma dca wmi nvidia_uvm(POE) sch_fq_codel parport_pc ppdev lp parport binder_linux(OE) ashmem_linux(OE) ip_tables x_tables autofs4 btrfs zstd_compress raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx libcrc32c xor raid6_pq raid1 raid0 multipath linear dm_mirror dm_region_hash dm_log input_leds hid_generic usbhid hid nvidia_drm(POE) nvidia_modeset(POE) nvidia(POE) drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops drm ahci libahci ipmi_devintf ipmi_msghandler mac_hid [last unloaded: zram]
Oct 27 11:27:34 kernel: [15526.726438] CPU: 6 PID: 14722 Comm: kworker/u32:9 Tainted: P W OE 5.0.0-23-generic #24~18.04.1-Ubuntu
Oct 27 11:27:34 kernel: [15526.726439] Hardware name: LENOVO 0606AD5/LENOVO, BIOS A0KT61AUS 03/27/2017
Oct 27 11:27:34 kernel: [15526.726442] Workqueue: writeback wb_workfn (flush-btrfs-1)
Oct 27 11:27:34 kernel: [15526.726462] RIP: 0010:find_free_extent+0xe79/0x1050 [btrfs]
Oct 27 11:27:34 kernel: [15526.726463] Code: ff ff b8 05 00 00 00 c7 85 48 ff ff ff 05 00 00 00 e9 a0 f2 ff ff 0f 0b e9 a3 fa ff ff 48 39 85 18 ff ff ff 0f 86 c6 f8 ff ff <0f> 0b 49 c7 44 24 28 00 00 00 00 e9 c2 f8 ff ff 65 8b 05 90 3f e1
Oct 27 11:27:34 kernel: [15526.726464] RSP: 0018:ffffa425c4317620 EFLAGS: 00010206
Oct 27 11:27:34 kernel: [15526.726465] RAX: 0000000000000000 RBX: ffff8d20ad2cdc00 RCX: 000000029e730000
Oct 27 11:27:34 kernel: [15526.726466] RDX: 0000000000000001 RSI: 0000000000000000 RDI: ffff8d20ad2cdc40
Oct 27 11:27:34 kernel: [15526.726467] RBP: ffffa425c4317708 R08: ffffffffffffffff R09: ffff8d20a29a0948
Oct 27 11:27:34 kernel: [15526.726468] R10: 0000000000000001 R11: 0000000000001000 R12: ffff8d20ab75e800
Oct 27 11:27:34 kernel: [15526.726469] R13: 0000000000000000 R14: ffff8d20ad2cdc40 R15: ffff8d20ab75e800
Oct 27 11:27:34 kernel: [15526.726471] FS: 0000000000000000(0000) GS:ffff8d20af980000(0000) knlGS:0000000000000000
Oct 27 11:27:34 kernel: [15526.726472] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Oct 27 11:27:34 kernel: [15526.726473] CR2: 00007f9ec3a1dfa0 CR3: 00000003ea008006 CR4: 00000000000606e0
Oct 27 11:27:34 kernel: [15526.726474] Call Trace:
Oct 27 11:27:34 kernel: [15526.726493] btrfs_reserve_extent+0x9b/0x1e0 [btrfs]
Oct 27 11:27:34 kernel: [15526.726515] cow_file_range.isra.64+0x125/0x410 [btrfs]
Oct 27 11:27:34 kernel: [15526.726536] run_delalloc_nocow+0x3c3/0xab0 [btrfs]
Oct 27 11:27:34 kernel: [15526.726558] btrfs_run_delalloc_range+0x1df/0x3d0 [btrfs]
Oct 27 11:27:34 kernel: [15526.726582] writepage_delalloc+0x103/0x150 [btrfs]
Oct 27 11:27:34 kernel: [15526.726607] __extent_writepage+0x17f/0x300 [btrfs]
Oct 27 11:27:34 kernel: [15526.726631] extent_write_cache_pages+0x176/0x440 [btrfs]
Oct 27 11:27:34 kernel: [15526.726655] extent_writepages+0x51/0x80 [btrfs]
Oct 27 11:27:34 kernel: [15526.726676] btrfs_writepages+0xe/0x10 [btrfs]
Oct 27 11:27:34 kernel: [15526.726679] do_writepages+0x4b/0xe0
Oct 27 11:27:34 kernel: [15526.726680] ? update_load_avg+0x8b/0x590
Oct 27 11:27:34 kernel: [15526.726682] ? update_load_avg+0x8b/0x590
Oct 27 11:27:34 kernel: [15526.726684] __writeback_single_inode+0x40/0x330
Oct 27 11:27:34 kernel: [15526.726687] ? __writeback_single_inode+0x40/0x330
Oct 27 11:27:34 kernel: [15526.726689] writeback_sb_inodes+0x1e6/0x510
Oct 27 11:27:34 kernel: [15526.726693] wb_writeback+0xfe/0x2f0
Oct 27 11:27:34 kernel: [15526.726695] ? native_usergs_sysret64+0x1/0x10
Oct 27 11:27:34 kernel: [15526.726698] wb_workfn+0xb3/0x400
Oct 27 11:27:34 kernel: [15526.726700] ? wb_workfn+0xb3/0x400
Oct 27 11:27:34 kernel: [15526.726702] ? __switch_to_asm+0x40/0x70
Oct 27 11:27:34 kernel: [15526.726704] process_one_work+0x1fd/0x400
Oct 27 11:27:34 kernel: [15526.726706] worker_thread+0x34/0x410
Oct 27 11:27:34 kernel: [15526.726709] kthread+0x121/0x140
Oct 27 11:27:34 kernel: [15526.726710] ? process_one_work+0x400/0x400
Oct 27 11:27:34 kernel: [15526.726713] ? kthread_park+0x90/0x90
Oct 27 11:27:34 kernel: [15526.726714] ret_from_fork+0x35/0x40
Oct 27 11:27:34 kernel: [15526.726716] ---[ end trace 3eef6955ffcfa157 ]---
Oct 27 11:27:34 kernel: [15526.772231] systemd-journald[598]: /dev/kmsg buffer overrun, some messages lost.
Oct 27 11:27:39 kernel: [15531.778086] BTRFS info (device sda3): found 15228 extents
Oct 27 11:27:39 kernel: [15531.814646] BTRFS info (device sda3): relocating block group 8611954688 flags data
Oct 27 11:27:39 kernel: [15531.940953] WARNING: CPU: 14 PID: 15349 at /build/linux-hwe-zHO4ZF/linux-hwe-5.0.0/fs/btrfs/extent-tree.c:69 find_free_extent+0xe79/0x1050 [btrfs]
Oct 27 11:27:39 kernel: [15531.940956] Modules linked in: bluetooth ecdh_generic msr xfs jfs tcp_diag inet_diag veth xt_CHECKSUM iptable_mangle xt_tcpudp ipt_MASQUERADE xt_comment iptable_nat nf_nat_ipv4 nf_nat bridge stp llc ip6t_REJECT nf_reject_ipv6 xt_NFLOG xt_u32 ipt_REJECT nf_reject_ipv4 xt_conntrack xt_connmark nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 nfnetlink_log nfnetlink nls_utf8 udf crc_itu_t pci_stub vboxpci(OE) vboxnetadp(OE) vboxnetflt(OE) vboxdrv(OE) snd_hda_codec_hdmi ip6table_filter ip6_tables iptable_filter bpfilter binfmt_misc intel_rapl sb_edac x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel aesni_intel aes_x86_64 crypto_simd cryptd glue_helper snd_hda_codec_realtek snd_hda_codec_generic ledtrig_audio wmi_bmof snd_hda_intel snd_hda_codec snd_hda_core snd_hwdep snd_pcm snd_seq_midi snd_seq_midi_event snd_rawmidi uas usb_storage intel_cstate snd_seq isci psmouse snd_seq_device intel_rapl_perf serio_raw snd_timer e1000e
Oct 27 11:27:39 kernel: [15531.941030] libsas mei_me scsi_transport_sas snd mei lpc_ich pata_acpi soundcore ioatdma dca wmi nvidia_uvm(POE) sch_fq_codel parport_pc ppdev lp parport binder_linux(OE) ashmem_linux(OE) ip_tables x_tables autofs4 btrfs zstd_compress raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx libcrc32c xor raid6_pq raid1 raid0 multipath linear dm_mirror dm_region_hash dm_log input_leds hid_generic usbhid hid nvidia_drm(POE) nvidia_modeset(POE) nvidia(POE) drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops drm ahci libahci ipmi_devintf ipmi_msghandler mac_hid [last unloaded: zram]
Oct 27 11:27:39 kernel: [15531.941071] CPU: 14 PID: 15349 Comm: kworker/u32:3 Tainted: P W OE 5.0.0-23-generic #24~18.04.1-Ubuntu
Oct 27 11:27:39 kernel: [15531.941073] Hardware name: LENOVO 0606AD5/LENOVO, BIOS A0KT61AUS 03/27/2017
Oct 27 11:27:39 kernel: [15531.941082] Workqueue: writeback wb_workfn (flush-btrfs-1)
Oct 27 11:27:39 kernel: [15531.941118] RIP: 0010:find_free_extent+0xe79/0x1050 [btrfs]
Oct 27 11:27:39 kernel: [15531.941121] Code: ff ff b8 05 00 00 00 c7 85 48 ff ff ff 05 00 00 00 e9 a0 f2 ff ff 0f 0b e9 a3 fa ff ff 48 39 85 18 ff ff ff 0f 86 c6 f8 ff ff <0f> 0b 49 c7 44 24 28 00 00 00 00 e9 c2 f8 ff ff 65 8b 05 90 3f e1
Oct 27 11:27:39 kernel: [15531.941123] RSP: 0018:ffffa425c2dcb718 EFLAGS: 00010206
Oct 27 11:27:39 kernel: [15531.941126] RAX: 0000000000000000 RBX: ffff8d20ad2cf400 RCX: 0000000076155000
Oct 27 11:27:39 kernel: [15531.941127] RDX: 0000000000000001 RSI: 0000000000000000 RDI: ffff8d20ad2cf440
Oct 27 11:27:39 kernel: [15531.941129] RBP: ffffa425c2dcb800 R08: 0000000000000000 R09: ffffffffc125df00
Oct 27 11:27:39 kernel: [15531.941131] R10: ffffa425c2dcb688 R11: 0000000000000001 R12: ffff8d20ab75e800
Oct 27 11:27:39 kernel: [15531.941132] R13: 0000000000000000 R14: ffff8d20ad2cf440 R15: ffff8d20ab75e800
Oct 27 11:27:39 kernel: [15531.941135] FS: 0000000000000000(0000) GS:ffff8d20afb80000(0000) knlGS:0000000000000000
Oct 27 11:27:39 kernel: [15531.941137] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Oct 27 11:27:39 kernel: [15531.941139] CR2: 00007f74e0a2c000 CR3: 00000003cfc6c002 CR4: 00000000000606e0
Oct 27 11:27:39 kernel: [15531.941141] Call Trace:
Oct 27 11:27:39 kernel: [15531.941177] btrfs_reserve_extent+0x9b/0x1e0 [btrfs]
Oct 27 11:27:39 kernel: [15531.941215] cow_file_range.isra.64+0x125/0x410 [btrfs]
Oct 27 11:27:39 kernel: [15531.941256] btrfs_run_delalloc_range+0xe3/0x3d0 [btrfs]
Oct 27 11:27:39 kernel: [15531.941304] writepage_delalloc+0x103/0x150 [btrfs]
Oct 27 11:27:39 kernel: [15531.941346] __extent_writepage+0x17f/0x300 [btrfs]
Oct 27 11:27:39 kernel: [15531.941395] extent_write_cache_pages+0x176/0x440 [btrfs]
Oct 27 11:27:39 kernel: [15531.941441] ? btrfs_submit_bio_hook+0x156/0x170 [btrfs]
Oct 27 11:27:39 kernel: [15531.941490] ? btrfs_retry_endio+0x140/0x140 [btrfs]
Oct 27 11:27:39 kernel: [15531.941543] extent_writepages+0x51/0x80 [btrfs]
Oct 27 11:27:39 kernel: [15531.941578] btrfs_writepages+0xe/0x10 [btrfs]
Oct 27 11:27:39 kernel: [15531.941584] do_writepages+0x4b/0xe0
Oct 27 11:27:39 kernel: [15531.941607] ? leaf_space_used+0xe5/0x110 [btrfs]
Oct 27 11:27:39 kernel: [15531.941612] __writeback_single_inode+0x40/0x330
Oct 27 11:27:39 kernel: [15531.941616] ? __writeback_single_inode+0x40/0x330
Oct 27 11:27:39 kernel: [15531.941621] writeback_sb_inodes+0x1e6/0x510
Oct 27 11:27:39 kernel: [15531.941626] wb_writeback+0xfe/0x2f0
Oct 27 11:27:39 kernel: [15531.941632] ? __kprobes_text_end+0x1c9120/0x1c9120
Oct 27 11:27:39 kernel: [15531.941639] wb_workfn+0xb3/0x400
Oct 27 11:27:39 kernel: [15531.941643] ? wb_workfn+0xb3/0x400
Oct 27 11:27:39 kernel: [15531.941647] ? __switch_to_asm+0x40/0x70
Oct 27 11:27:39 kernel: [15531.941655] process_one_work+0x1fd/0x400
Oct 27 11:27:39 kernel: [15531.941658] worker_thread+0x34/0x410
Oct 27 11:27:39 kernel: [15531.941663] kthread+0x121/0x140
Oct 27 11:27:39 kernel: [15531.941667] ? process_one_work+0x400/0x400
Oct 27 11:27:39 kernel: [15531.941672] ? kthread_park+0x90/0x90
Oct 27 11:27:39 kernel: [15531.941676] ret_from_fork+0x35/0x40
Oct 27 11:27:39 kernel: [15531.941681] ---[ end trace 3eef6955ffcfa158 ]---

And so on, ad infinitum.

Following a reboot it apparently tries to continue, before it finally bailed in an apparently more sane manner.

Oct 27 11:32:37 kernel: [ 10.255879] BTRFS info (device sda3): balance: resume -f -dusage=90 -musage=90 -susage=90
Oct 27 11:32:37 kernel: [ 10.255971] BTRFS info (device sda3): relocating block group 109154664448 flags metadata
Oct 27 11:32:37 kernel: [ 10.282915] BTRFS info (device sda3): relocating block group 107396202496 flags data
Oct 27 11:32:40 kernel: [ 13.691864] BTRFS info (device sda3): found 294 extents
Oct 27 11:32:44 kernel: [ 17.383183] BTRFS info (device sda3): found 294 extents
Oct 27 11:32:44 kernel: [ 17.422274] BTRFS info (device sda3): relocating block group 13631488 flags data
Oct 27 11:32:44 kernel: [ 17.479307] BTRFS info (device sda3): found 33 extents
Oct 27 11:32:44 kernel: [ 17.570849] BTRFS info (device sda3): found 29 extents
Oct 27 11:32:44 kernel: [ 17.597194] BTRFS info (device sda3): relocating block group 5242880 flags metadata
Oct 27 11:32:44 kernel: [ 17.762133] BTRFS info (device sda3): found 68 extents
Oct 27 11:32:44 kernel: [ 17.812847] BTRFS info (device sda3): relocating block group 1048576 flags system
Oct 27 11:32:44 kernel: [ 17.843576] BTRFS info (device sda3): found 1 extents
Oct 27 11:32:44 kernel: [ 17.873811] BTRFS info (device sda3): 1 enospc errors during balance
Oct 27 11:32:44 kernel: [ 17.873814] BTRFS info (device sda3): balance: ended with status: -28

I'll have to complete a full backup before attempting anything with an upstream kernel.

ProblemType: Bug
DistroRelease: Ubuntu 18.04
Package: linux-image-5.0.0-23-generic 5.0.0-23.24~18.04.1
ProcVersionSignature: Ubuntu 5.0.0-23.24~18.04.1-generic 5.0.15
Uname: Linux 5.0.0-23-generic x86_64
NonfreeKernelModules: nvidia_modeset nvidia
ApportVersion: 2.20.9-0ubuntu7.7
Architecture: amd64
CurrentDesktop: MATE
Date: Sun Oct 27 11:34:14 2019
InstallationDate: Installed on 2019-06-09 (139 days ago)
InstallationMedia: Ubuntu-MATE 18.04.2 LTS "Bionic Beaver" - Release amd64 (20190210)
SourcePackage: linux-signed-hwe
UpgradeStatus: No upgrade log present (probably fresh install)