[ 5764.201343] kernel: BTRFS warning (device vda3): Skipping commit of aborted transaction. [ 5764.201347] kernel: ------------[ cut here ]------------ [ 5764.201350] kernel: BTRFS: Transaction aborted (error -28) [ 5764.205829] kernel: WARNING: CPU: 1 PID: 467 at fs/btrfs/transaction.c:1908 cleanup_transaction+0x51/0xb0 [btrfs] [ 5764.205883] kernel: Modules linked in: nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct nft_chain_nat nf_tables ebtable_nat ebtable_broute ip6table_nat ip6table_mangle ip6table_raw ip6table_security iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 iptable_mangle iptable_raw iptable_security ip_set nfnetlink ebtable_filter ebtables ip6table_filter ip6_tables iptable_filter intel_rapl_msr intel_rapl_common kvm_intel snd_hda_codec_generic ledtrig_audio kvm snd_hda_intel snd_intel_dspcfg snd_hda_codec snd_hda_core sunrpc snd_hwdep snd_seq snd_seq_device iTCO_wdt irqbypass iTCO_vendor_support snd_pcm joydev virtio_balloon snd_timer snd soundcore lpc_ich i2c_i801 vfat fat xfs zram ip_tables crct10dif_pclmul crc32_pclmul ghash_clmulni_intel serio_raw virtio_gpu drm_kms_helper virtio_blk cec virtio_console drm virtio_net net_failover failover qemu_fw_cfg btrfs blake2b_generic xor raid6_pq libcrc32c crc32c_intel fuse [ 5764.206074] kernel: CPU: 1 PID: 467 Comm: btrfs-transacti Not tainted 5.7.0-1.fc33.x86_64 #1 [ 5764.206076] kernel: Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 0.0.0 02/06/2015 [ 5764.206132] kernel: RIP: 0010:cleanup_transaction+0x51/0xb0 [btrfs] [ 5764.206138] kernel: Code: 77 66 f0 49 0f ba ad 40 0a 00 00 02 72 1e 41 83 fc fb 75 07 0f 1f 44 00 00 eb 11 44 89 e6 48 c7 c7 18 71 47 c0 e8 b6 7d d1 e0 <0f> 0b 44 89 e1 ba 74 07 00 00 49 8d 5e 28 48 89 ef 48 c7 c6 50 b5 [ 5764.206141] kernel: RSP: 0018:ffffa1eec02bbdf8 EFLAGS: 00010292 [ 5764.206144] kernel: RAX: 0000000000000026 RBX: 00000000ffffffe4 RCX: 0000000000000007 [ 5764.206147] kernel: RDX: 00000000fffffff8 RSI: 0000000000000092 RDI: ffff962f7d919cc0 [ 5764.206149] kernel: RBP: ffff962f75247f08 R08: 000000000000063e R09: 0000000000000003 [ 5764.206151] kernel: R10: 0000000000000000 R11: 0000000000000001 R12: 00000000ffffffe4 [ 5764.206153] kernel: R13: ffff962f741bc000 R14: ffff962f734bd000 R15: ffff962f75247e58 [ 5764.206157] kernel: FS: 0000000000000000(0000) GS:ffff962f7d900000(0000) knlGS:0000000000000000 [ 5764.206159] kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 5764.206161] kernel: CR2: 000055b406ef4028 CR3: 0000000044928006 CR4: 0000000000360ee0 [ 5764.206174] kernel: Call Trace: [ 5764.206405] kernel: btrfs_commit_transaction+0x298/0xa00 [btrfs] [ 5764.206570] kernel: ? start_transaction+0xd2/0x4c0 [btrfs] [ 5764.206614] kernel: transaction_kthread+0x13c/0x180 [btrfs] [ 5764.206656] kernel: ? btrfs_cleanup_transaction.isra.0+0x580/0x580 [btrfs] [ 5764.206816] kernel: kthread+0x115/0x140 [ 5764.206890] kernel: ? __kthread_bind_mask+0x60/0x60 [ 5764.207204] kernel: ret_from_fork+0x35/0x40 [ 5764.207271] kernel: ---[ end trace cbc8af43875b57a5 ]--- [ 5764.207466] kernel: BTRFS: error (device vda3) in cleanup_transaction:1908: errno=-28 No space left $ findmnt /dev/vda3 TARGET SOURCE FSTYPE OPTIONS / /dev/vda3[/root] btrfs ro,relatime,seclabel,space_cache,subvolid=256,subvol=/root $ cat /sys/block/vda/vda3/ro 1 $ uname -r 5.7.0-1.fc33.x86_64 This happens when booting with the disk in read-only mode using the new systemd param udev.blockdev_read_only (systemd 246). The issue is to some extent just cosmetic: after all, nothing has happened. But a kernel backtrace results in warnings on the console and notification popups, which scares users.
The block device itself is ro, I wonder if that's what's causing confusion. Even ro mounted btrfs might still write. But it looks like this call trace happens well after boot, is it the first trace or is it repeating?
Well that's neat. The ENOSPC is because we see that the device is read only, and thus mark all of its block groups read only. However the fs must be mounted RW, so when it goes to allocate something it can't find space, because it's all read only, and then flips ro when the transaction aborts. Not a problem per-se, just not what we should do probably. I'll reproduce locally and fix it up.
> this call trace happens well after boot Yes. > is it the first trace or is it repeating? I've seen it just once, although I have been booting in this mode for debugging dozens of times. It doesn't seem repeatable. > However the fs must be mounted RW I don't think so. We indeed try to mount the fs rw (because configuration says so), but the device is already read-only when the initial mount happens. The logs don't show the message about the fs being mounted ro, so there might be some confusion about the ro/rw status. In the logs I see: [ 3.803178] systemd-udevd[390]: vda3: Successfully marked block device '/dev/vda3' read-only. [ 3.974356] kernel: BTRFS: device label fedora devid 1 transid 255974 /dev/vda3 scanned by systemd-udevd (390) [ 3.993144] systemd[1]: dev-vda3.device: Changed dead -> plugged [ 3.993191] systemd[1]: sys-devices-pci0000:00-0000:00:02.3-0000:04:00.0-virtio3-block-vda-vda3.device: Changed dead -> plugged [ 4.020148] kernel: BTRFS info (device vda3): disk space caching is enabled [ 4.020150] kernel: BTRFS info (device vda3): has skinny extents ... [ 11.534268] kernel: BTRFS info (device vda3): disk space caching is enabled ... [ 22.248465] systemd-remount-fs[545]: mount: /: cannot remount /dev/vda3 read-write, is write-protected. ... [ 5764.201343] kernel: BTRFS warning (device vda3): Skipping commit of aborted transaction. That message about remounting is from systemd-remount-fs.service which tries to remount rw because /etc/fstab says so.
Variation on this with a seed device and scrubbing with -r. Same basic problem, looks like. [634473.213348] BTRFS warning (device dm-1): Skipping commit of aborted transaction. [634473.213350] ------------[ cut here ]------------ [634473.213353] BTRFS: Transaction aborted (error -28) [634473.213518] WARNING: CPU: 0 PID: 22091 at fs/btrfs/transaction.c:1908 cleanup_transaction+0x51/0xb0 [btrfs] [634473.213519] Modules linked in: <snipped> [634473.213582] CPU: 0 PID: 22091 Comm: btrfs-transacti Not tainted 5.7.4-200.fc32.x86_64 #1 [634473.213583] Hardware name: /NUC5PPYB, BIOS PYBSWCEL.86A.0079.2020.0420.1316 04/20/2020 [634473.213614] RIP: 0010:cleanup_transaction+0x51/0xb0 [btrfs] [634473.213618] Code: 77 66 f0 49 0f ba ad 40 0a 00 00 02 72 1e 41 83 fc fb 75 07 0f 1f 44 00 00 eb 11 44 89 e6 48 c7 c7 18 a1 1c c0 e8 f6 4c fc d2 <0f> 0b 44 89 e1 ba 74 07 00 00 49 8d 5e 28 48 89 ef 48 c7 c6 50 e5 [634473.213620] RSP: 0018:ffffa971035abdf8 EFLAGS: 00010292 [634473.213622] RAX: 0000000000000026 RBX: 00000000ffffffe4 RCX: 0000000000000007 [634473.213623] RDX: 00000000fffffff8 RSI: 0000000000000092 RDI: ffff9cbc3bc19cc0 [634473.213624] RBP: ffff9cbc39d1ca90 R08: 00000000000004b3 R09: 0000000000000003 [634473.213625] R10: 0000000000000000 R11: 0000000000000001 R12: 00000000ffffffe4 [634473.213626] R13: ffff9cbbdece3000 R14: ffff9cbad0daea00 R15: ffff9cbc39d1c9e0 [634473.213629] FS: 0000000000000000(0000) GS:ffff9cbc3bc00000(0000) knlGS:0000000000000000 [634473.213630] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [634473.213631] CR2: 00007f5e082f25c0 CR3: 000000011180a000 CR4: 00000000001006f0 [634473.213633] Call Trace: [634473.213671] btrfs_commit_transaction+0x298/0xa00 [btrfs] [634473.213702] ? start_transaction+0xd2/0x4c0 [btrfs] [634473.213731] transaction_kthread+0x13c/0x180 [btrfs] [634473.213761] ? btrfs_cleanup_transaction.isra.0+0x580/0x580 [btrfs] [634473.213766] kthread+0x115/0x140 [634473.213769] ? __kthread_bind_mask+0x60/0x60 [634473.213774] ret_from_fork+0x35/0x40 [634473.213777] ---[ end trace 9ff2e597a03c46d2 ]--- [634473.213782] BTRFS: error (device dm-1) in cleanup_transaction:1908: errno=-28 No space left [634473.229133] BTRFS info (device dm-1): scrub: not finished on devid 1 with status: -125 [chris@fnuc ~]$
Curious, I can reproduce this in the btrfs seed + scrub -r case. But it doesn't happen when booting with udev.blockdev_read_only Feb 09 15:52:30 fmac.local kernel: BTRFS info (device sdb1): scrub: started on devid 1 Feb 09 15:53:01 fmac.local kernel: BTRFS warning (device sdb1): Skipping commit of aborted transaction. Feb 09 15:53:01 fmac.local kernel: ------------[ cut here ]------------ Feb 09 15:53:01 fmac.local kernel: BTRFS: Transaction aborted (error -28) Feb 09 15:53:01 fmac.local kernel: WARNING: CPU: 1 PID: 1636 at fs/btrfs/transaction.c:1938 btrfs_commit_transaction+0xa65/0xb80 Feb 09 15:53:01 fmac.local kernel: Modules linked in: rfcomm snd_seq_dummy snd_hrtimer xt_CHECKSUM xt_MASQUERADE xt_conntrack ipt_REJECT nf_nat_tftp nf_conntrack_tftp bridge stp llc nft_objref nf_conntrack_netbios_ns nf_conntrack_broadcast nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct nft_chain_nat ip6table_nat ip6table_mangle ip6table_raw ip6table_security iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 iptable_mangle iptable_raw iptable_security ip_set nf_tables nfnetlink ip6table_filter ip6_tables iptable_filter bnep sunrpc nls_utf8 hfsplus b43 cordic ssb mac80211 libarc4 intel_rapl_msr intel_rapl_common x86_pkg_temp_thermal intel_powerclamp cfg80211 snd_hda_codec_cirrus snd_hda_codec_generic uvcvideo snd_hda_intel snd_intel_dspcfg coretemp snd_hda_codec firewire_sbp2 iTCO_wdt videobuf2_vmalloc intel_pmc_bxt kvm_intel btusb joydev at24 mei_hdcp btrtl iTCO_vendor_support btbcm btintel snd_hwdep videobuf2_memops kvm bluetooth Feb 09 15:53:01 fmac.local kernel: irqbypass snd_hda_core applesmc videobuf2_v4l2 rapl intel_cstate snd_seq videobuf2_common ecdh_generic videodev ecc snd_seq_device intel_uncore snd_pcm rfkill mc snd_timer i2c_i801 bcm5974 i2c_smbus apple_mfi_fastcharge snd bcma lpc_ich soundcore mei_me sbs apple_gmux acpi_als mei kfifo_buf industrialio sbshc apple_bl zram ip_tables i915 i2c_algo_bit drm_kms_helper cec drm sdhci_pci cqhci crct10dif_pclmul sdhci crc32_pclmul crc32c_intel mmc_core ghash_clmulni_intel firewire_ohci tg3 firewire_core hid_appleir crc_itu_t video hid_apple fuse Feb 09 15:53:01 fmac.local kernel: CPU: 1 PID: 1636 Comm: btrfs-transacti Not tainted 5.11.0-rc7 #4 Feb 09 15:53:01 fmac.local kernel: Hardware name: Apple Inc. MacBookPro8,2/Mac-94245A3940C91C80, BIOS MBP81.88Z.0050.B00.1804101331 04/10/18 Feb 09 15:53:01 fmac.local kernel: RIP: 0010:btrfs_commit_transaction+0xa65/0xb80 Feb 09 15:53:01 fmac.local kernel: Code: 00 f0 49 0f ba ac 24 48 0a 00 00 03 72 1e 83 fb fb 0f 84 84 00 00 00 83 fb e2 74 7f 89 de 48 c7 c7 a0 86 3c a8 e8 d9 30 6c 00 <0f> 0b 89 d9 ba 92 07 00 00 4d 8d 7d 28 48 89 ef 48 c7 c6 90 60 06 Feb 09 15:53:01 fmac.local kernel: RSP: 0018:ffffb82241787de8 EFLAGS: 00010292 Feb 09 15:53:01 fmac.local kernel: RAX: 0000000000000026 RBX: 00000000ffffffe4 RCX: 0000000000000027 Feb 09 15:53:01 fmac.local kernel: RDX: ffff8d4ee3258ac8 RSI: 0000000000000001 RDI: ffff8d4ee3258ac0 Feb 09 15:53:01 fmac.local kernel: RBP: ffff8d4c9ca44a90 R08: 0000000000000000 R09: ffffb82241787c18 Feb 09 15:53:01 fmac.local kernel: R10: ffffb82241787c10 R11: ffff8d4eefbf6fe8 R12: ffff8d4c8865d000 Feb 09 15:53:01 fmac.local kernel: R13: ffff8d4c83a41a00 R14: ffff8d4c9ca449e0 R15: ffff8d4c9ca449e0 Feb 09 15:53:01 fmac.local kernel: FS: 0000000000000000(0000) GS:ffff8d4ee3240000(0000) knlGS:0000000000000000 Feb 09 15:53:01 fmac.local kernel: CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 Feb 09 15:53:01 fmac.local kernel: CR2: 00007f1ed17b6000 CR3: 0000000243a10006 CR4: 00000000000606e0 Feb 09 15:53:01 fmac.local kernel: Call Trace: Feb 09 15:53:01 fmac.local kernel: transaction_kthread+0x12b/0x190 Feb 09 15:53:01 fmac.local kernel: ? btrfs_cleanup_transaction.isra.0+0x580/0x580 Feb 09 15:53:01 fmac.local kernel: kthread+0x11b/0x140 Feb 09 15:53:01 fmac.local kernel: ? kthread_associate_blkcg+0xa0/0xa0 Feb 09 15:53:01 fmac.local kernel: ret_from_fork+0x1f/0x30 Feb 09 15:53:01 fmac.local kernel: ---[ end trace 3d83e97531570ea7 ]--- Feb 09 15:53:01 fmac.local kernel: BTRFS: error (device sdb1) in cleanup_transaction:1938: errno=-28 No space left Feb 09 15:53:01 fmac.local kernel: BTRFS info (device sdb1): scrub: not finished on devid 1 with status: -125
Not seeing this with a 5.17.5 kernel, probably fixed a while ago.