btrfs forcing read-only after suspend or at random times

epicepee · 2017-03-18 04:57:38

I run Arch on an SSD in a Dell E5470. /home is on a different subvolume, but the same partition, as /. btrfs-progs is up to date.

I have recently had issues with btrfs forcing itself into read-only mode either after suspend/resume or simply after a period of inactivity. Everything else keeps working as expected, including mounting other partitions. I have tried:

btrfs scrub
btrfs check --repair (mentions something about backrefs, does not seem to solve it)
btrfs check --repair --init-csum-tree
btrfs check --repair --init-extent-tree

Here is a dmesg from one of the occasions. The first line is from boot time, to show that nothing happened beforehand. The last line is the last which was shown (because the filesystem died?).

[   20.359181] Bluetooth: RFCOMM ver 1.11
[ 2313.475243] Process accounting resumed
[ 2435.594648] BTRFS error (device sda2): trying to drop 3 refs but we only have 2 for bytenr 3595124736
[ 2435.594659] ------------[ cut here ]------------
[ 2435.594699] WARNING: CPU: 2 PID: 170 at fs/btrfs/extent-tree.c:7005 __btrfs_free_extent.isra.21+0xb08/0xe80 [btrfs]
[ 2435.594702] BTRFS: Transaction aborted (error -22)
[ 2435.594704] Modules linked in: rfcomm fuse tun snd_hda_codec_hdmi dell_led bnep snd_hda_codec_realtek snd_hda_codec_generic joydev mousedev snd_soc_skl snd_soc_skl_ipc snd_soc_sst_ipc snd_soc_sst_dsp snd_hda_ext_core snd_soc_sst_match snd_soc_core snd_compress snd_pcm_dmaengine ac97_bus arc4 iTCO_wdt iTCO_vendor_support intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel dell_wmi uvcvideo dell_laptop sparse_keymap dell_smbios videobuf2_vmalloc wl(PO) videobuf2_memops mei_wdt dcdbas ppdev pcbc iwlmvm videobuf2_v4l2 videobuf2_core aesni_intel videodev aes_x86_64 crypto_simd glue_helper mac80211 dell_smm_hwmon media cryptd intel_cstate intel_rapl_perf btusb snd_hda_intel btrtl snd_hda_codec snd_hda_core iwlwifi psmouse snd_hwdep
[ 2435.594812]  evdev input_leds e1000e led_class mac_hid snd_pcm ptp snd_timer pps_core i2c_i801 snd cfg80211 soundcore rtsx_pci_ms memstick i915 shpchp drm_kms_helper drm intel_gtt syscopyarea mei_me sysfillrect sysimgblt mei fb_sys_fops processor_thermal_device i2c_algo_bit intel_pch_thermal intel_soc_dts_iosf thermal wmi battery hci_uart btbcm btqca btintel bluetooth parport_pc parport video dell_smo8800 i2c_hid crc16 intel_lpss_acpi hid intel_lpss dell_rbtn int3403_thermal int340x_thermal_zone int3400_thermal acpi_als rfkill acpi_thermal_rel kfifo_buf industrialio acpi_pad ac fjes tpm_tis tpm_tis_core tpm button sch_fq_codel vboxnetflt(O) vboxnetadp(O) pci_stub vboxpci(O) vboxdrv(O) sg ip_tables x_tables btrfs xor raid6_pq sd_mod rtsx_pci_sdmmc mmc_core serio_raw atkbd libps2 crc32c_intel xhci_pci
[ 2435.594947]  ahci xhci_hcd libahci libata rtsx_pci scsi_mod usbcore usb_common i8042 serio
[ 2435.594976] CPU: 2 PID: 170 Comm: btrfs-transacti Tainted: P           O    4.10.3-1-ck-skylake #1
[ 2435.594978] Hardware name: Dell Inc. Latitude E5470/      , BIOS 1.11.4 12/22/2016
[ 2435.594981] Call Trace:
[ 2435.594998]  dump_stack+0x63/0x83
[ 2435.595007]  __warn+0xcb/0xf0
[ 2435.595015]  warn_slowpath_fmt+0x5f/0x80
[ 2435.595048]  __btrfs_free_extent.isra.21+0xb08/0xe80 [btrfs]
[ 2435.595082]  __btrfs_run_delayed_refs+0x533/0x1360 [btrfs]
[ 2435.595118]  btrfs_run_delayed_refs+0x8a/0x2a0 [btrfs]
[ 2435.595159]  btrfs_commit_transaction+0x48/0x930 [btrfs]
[ 2435.595193]  ? start_transaction+0x99/0x470 [btrfs]
[ 2435.595230]  transaction_kthread+0x174/0x1b0 [btrfs]
[ 2435.595237]  kthread+0x101/0x140
[ 2435.595268]  ? btrfs_cleanup_transaction+0x520/0x520 [btrfs]
[ 2435.595274]  ? kthread_create_on_node+0x60/0x60
[ 2435.595281]  ret_from_fork+0x2c/0x40
[ 2435.595287] ---[ end trace 68213e8942870ca9 ]---
[ 2435.595293] BTRFS: error (device sda2) in __btrfs_free_extent:7005: errno=-22 unknown
[ 2435.595300] BTRFS info (device sda2): forced readonly
[ 2435.595306] BTRFS: error (device sda2) in btrfs_run_delayed_refs:2956: errno=-22 unknown
[ 2435.595786] BTRFS error (device sda2): pending csums is 13049856

Any experiences or suggestions, or more info to collect?
Thank you!

ratcheer · 2017-03-18 12:41:32

Did you convert the filesystem from ext4? If Yes, you need to "btrfs subvolume delete" the subvolume that contains the backup of the ext4 filesystem before using the new btrfs filesystem. I learned this the hard way, and it took me several days to find out.

If No, then I don't know. You can get better help on the btrfs Mail List.

Tim

epicepee · 2017-03-18 18:47:58

No, I didn't; it was supposed to be unstable when I switched over so I just copied all of the files.

seth · 2017-03-18 20:05:30

https://wiki.archlinux.org/index.php/S.M.A.R.T.

Pray it's a btrfs bug ;-)

epicepee · 2017-03-20 15:13:28

Update: this can be triggered by trying to defrag. I'm assuming there is a particular file which causes it; I'll try to find it.

lamarpavel · 2017-03-27 13:41:33

I have a similar issue, though with slightly different error report. In my case it's a server with btrfs on the root partition. After 30 days and a few hours of uptime the partition was suddenly RO.

dmesg wrote:

...
[2584261.394884] ------------[ cut here ]------------
[2584261.394907] WARNING: CPU: 3 PID: 191 at fs/btrfs/extent-tree.c:6961 __btrfs_free_extent.isra.33+0x79c/0xca0 [btrfs]
[2584261.394908] BTRFS: Transaction aborted (error -5)
[2584261.394908] Modules linked in: cfg80211 rfkill nct6775 hwmon_vid iTCO_wdt iTCO_vendor_support evdev mei_wdt mac_hid intel_rapl ppdev x86_pkg_temp_thermal i915 snd_hda_codec_hdmi intel_powerclamp coretemp kvm_intel kvm snd_hda_codec_realtek nls_iso8859_1 snd_hda_codec_generic nls_cp437 irqbypass crct10dif_pclmul crc32_pclmul vfat snd_hda_intel r8169 ghash_clmulni_intel psmouse fat drm_kms_helper cryptd intel_cstate i2c_i801 intel_rapl_perf pcspkr i2c_smbus mii lpc_ich snd_hda_codec parport_pc nuvoton_cir battery drm parport snd_hda_core rc_core snd_hwdep snd_pcm intel_gtt fjes snd_timer syscopyarea sysfillrect tpm_tis sysimgblt video tpm_tis_core fb_sys_fops i2c_algo_bit mei_me button snd intel_smartconnect tpm mei soundcore shpchp nfsd auth_rpcgss oid_registry nfs_acl lockd grace sunrpc sch_fq_codel
[2584261.394944] ip_tables x_tables btrfs sd_mod serio_raw atkbd libps2 xhci_pci xhci_hcd ahci libahci libata ehci_pci ehci_hcd scsi_mod usbcore usb_common i8042 serio raid456 libcrc32c crc32c_generic crc32c_intel async_raid6_recov async_memcpy async_pq async_xor async_tx md_mod xor raid6_pq ext4 crc16 jbd2 fscrypto mbcache
[2584261.394962] CPU: 3 PID: 191 Comm: btrfs-transacti Tainted: G W 4.9.11-1-ARCH #1
[2584261.394962] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./B75M-GL R2.0, BIOS P1.30 03/02/2013
[2584261.394964] ffffc900012e3b38 ffffffff81305830 ffffc900012e3b88 0000000000000000
[2584261.394966] ffffc900012e3b78 ffffffff8107eb3b 00001b3181606077 000000003f23c000
[2584261.394968] 00000000fffffffb ffff88021249d140 ffff88008dd43770 0000000000000000
[2584261.394970] Call Trace:
[2584261.394975] [<ffffffff81305830>] dump_stack+0x63/0x83
[2584261.394977] [<ffffffff8107eb3b>] __warn+0xcb/0xf0
[2584261.394979] [<ffffffff8107ebbf>] warn_slowpath_fmt+0x5f/0x80
[2584261.394987] [<ffffffffa033ee0c>] __btrfs_free_extent.isra.33+0x79c/0xca0 [btrfs]
[2584261.394997] [<ffffffffa03b1c53>] ? btrfs_merge_delayed_refs+0x93/0x600 [btrfs]
[2584261.395005] [<ffffffffa0343724>] __btrfs_run_delayed_refs+0xa74/0x13a0 [btrfs]
[2584261.395008] [<ffffffff810f04ea>] ? try_to_del_timer_sync+0x5a/0x80
[2584261.395016] [<ffffffffa0347195>] btrfs_run_delayed_refs+0xa5/0x2b0 [btrfs]
[2584261.395025] [<ffffffffa035ea19>] btrfs_commit_transaction+0x29/0x70 [btrfs]
[2584261.395034] [<ffffffffa0358dcb>] transaction_kthread+0x1ab/0x1e0 [btrfs]
[2584261.395042] [<ffffffffa0358c20>] ? btrfs_cleanup_transaction+0x570/0x570 [btrfs]
[2584261.395043] [<ffffffff8109e939>] kthread+0xd9/0xf0
[2584261.395045] [<ffffffff8102d752>] ? __switch_to+0x2d2/0x630
[2584261.395046] [<ffffffff8109e860>] ? kthread_park+0x60/0x60
[2584261.395048] [<ffffffff8160ad55>] ret_from_fork+0x25/0x30
[2584261.395049] ---[ end trace 96673e227a55d9f5 ]---
[2584261.395051] BTRFS: error (device sda3) in __btrfs_free_extent:6961: errno=-5 IO failure
[2584261.395084] BTRFS info (device sda3): forced readonly
[2584261.395086] BTRFS: error (device sda3) in btrfs_run_delayed_refs:2967: errno=-5 IO failure
[2584261.395171] BTRFS error (device sda3): pending csums is 8192
[2586484.785994] BTRFS warning (device sda3): sda3 checksum verify failed on 1061208064 wanted A63E7B9B found 83B40546 level 0
[2586484.786038] BTRFS info (device sda3): no csum found for inode 42300 start 290816
[2586484.786246] BTRFS warning (device sda3): csum failed ino 42300 off 290816 csum 4231670480 expected csum 0
[2586484.876291] BTRFS error (device sda3): parent transid verify failed on 1061208064 wanted 376563 found 374912
[2586484.876348] BTRFS info (device sda3): no csum found for inode 26488562 start 0
[2586484.876842] BTRFS error (device sda3): parent transid verify failed on 1061208064 wanted 376563 found 374912
[2586484.876903] BTRFS info (device sda3): no csum found for inode 26488562 start 4096
[2586484.877203] BTRFS error (device sda3): parent transid verify failed on 1061208064 wanted 376563 found 374912
[2586484.877264] BTRFS info (device sda3): no csum found for inode 26488562 start 8192
[2586484.877465] BTRFS warning (device sda3): csum failed ino 26488562 off 0 csum 2653021561 expected csum 0
[2586484.877472] BTRFS warning (device sda3): csum failed ino 26488562 off 4096 csum 3578613924 expected csum 0
[2586484.877484] BTRFS warning (device sda3): csum failed ino 26488562 off 8192 csum 209569538 expected csum 0
[2617719.685000] BTRFS error (device sda3): parent transid verify failed on 1061208064 wanted 376563 found 374912
[2617719.685102] BTRFS info (device sda3): no csum found for inode 42300 start 290816
[2617719.685290] BTRFS warning (device sda3): csum failed ino 42300 off 290816 csum 4231670480 expected csum 0
[2618199.240046] BTRFS error (device sda3): parent transid verify failed on 1061208064 wanted 376563 found 374912
[2618199.240131] BTRFS info (device sda3): no csum found for inode 42300 start 290816
[2618199.240361] BTRFS warning (device sda3): csum failed ino 42300 off 290816 csum 4231670480 expected csum 0
[2619502.864942] BTRFS critical (device sda3): corrupt node, bad key order: block=1060487168, root=1, slot=261
[2619686.844175] BTRFS critical (device sda3): corrupt node, bad key order: block=1060487168, root=1, slot=261

I first tried non-invasive checks like btrfs check --readonly -p /dev/sda3 but that required the device to be unmounted and since we are talking about the root partition, I settled for a reboot first.
Unfortunately the system wasn't booting anymore. Using a live-iso I performed the above check and got

Checking filesystem on /dev/sda3
UUID: 15bb36cd-...
bad block 1060487168
Errors found in extent allocation tree or chunk allocation

root@archiso ~ # btrfs rescue super-recover -v /dev/sda3
All supers are valid, no need to recover

root@archiso ~ # btrfs rescue chunk-recover -v /dev/sda3
...
[listing of Block Groups]
...
Total Chunks: 73
Recoverable: 73
Unrecoverable: 0
Orphan Block Groups:
Orphan Device Extents:
Check chunks successfully with no orphans
Chunk tree recovered successfully
btrfs rescue chunk-recover -v /dev/sda3 4.93s user 191.13s system 45% cpu 7:06.27 total

However, btrfs check -p /dev/sda3 still results in:

Checking filesystem on /dev/sda3
UUID: 15bb36cd-...
bad block 1060487168
Errors found in extent allocation tree or chunk allocation

I can mount the system now with root@archiso ~ # mount -t btrfs -o recovery,nospace_cache,clear_cache /dev/sda3 /mnt but I dare not modify any files.

The main difference I can see to your description is the dmesg output where I get BTRFS: error (device sda3) in __btrfs_free_extent:6961: errno=-5 IO failure before the forced readonly while you get a BTRFS: error (device sda2) in __btrfs_free_extent:7005: errno=-22 unknown.

Have you made any progress since?

Arch Linux

#1 2017-03-18 04:57:38

btrfs forcing read-only after suspend or at random times

#2 2017-03-18 12:41:32

Re: btrfs forcing read-only after suspend or at random times

#3 2017-03-18 18:47:58

Re: btrfs forcing read-only after suspend or at random times

#4 2017-03-18 20:05:30

Re: btrfs forcing read-only after suspend or at random times

#5 2017-03-20 15:13:28

Re: btrfs forcing read-only after suspend or at random times

#6 2017-03-27 13:41:33

Re: btrfs forcing read-only after suspend or at random times

Board footer