Cdtjkyj

Since today, when I try to write moderate amounts of data (MB range) to the btrfs volume on my external hard drive, the volume switches to read-only, interrupting the operation. The volume is very simple (no RAID, no snapshots).

journalctl shows the following around the time of the writes:

Jan 23 18:34:16 my-machine kernel: BTRFS: device label <...> devid 1 transid 3344 /dev/sdb1

Jan 23 18:34:16 my-machine kernel: BTRFS info (device sdb1): disk space caching is enabled

Jan 23 18:34:16 my-machine kernel: BTRFS info (device sdb1): has skinny extents

Jan 23 18:36:35 my-machine kernel: BTRFS critical (device sdb1): corrupt node: root=7 block=253655810048 slot=106, bad key order, current (18446744073709551606 128 9223372601711906816) next (18446744073709551606 128 564873670656)

Jan 23 18:38:13 my-machine kernel: BTRFS critical (device sdb1): corrupt node: root=7 block=253655810048 slot=106, bad key order, current (18446744073709551606 128 9223372601711906816) next (18446744073709551606 128 564873670656)

Jan 23 18:39:43 my-machine kernel: BTRFS critical (device sdb1): corrupt node: root=7 block=253655810048 slot=106, bad key order, current (18446744073709551606 128 9223372601711906816) next (18446744073709551606 128 564873670656)

Jan 23 18:40:58 my-machine kernel: BTRFS critical (device sdb1): corrupt node: root=7 block=253655810048 slot=106, bad key order, current (18446744073709551606 128 9223372601711906816) next (18446744073709551606 128 564873670656)

Jan 23 18:42:28 my-machine kernel: BTRFS critical (device sdb1): corrupt node: root=7 block=253655810048 slot=106, bad key order, current (18446744073709551606 128 9223372601711906816) next (18446744073709551606 128 564873670656)

Jan 23 18:42:39 my-machine kernel: BTRFS critical (device sdb1): corrupt node: root=7 block=253655810048 slot=106, bad key order, current (18446744073709551606 128 9223372601711906816) next (18446744073709551606 128 564873670656)

Jan 23 18:42:39 my-machine kernel: BTRFS critical (device sdb1): corrupt node: root=7 block=253655810048 slot=106, bad key order, current (18446744073709551606 128 9223372601711906816) next (18446744073709551606 128 564873670656)

Jan 23 18:42:39 my-machine kernel: BTRFS: error (device sdb1) in btrfs_finish_ordered_io:3074: errno=-5 IO failure

Jan 23 18:42:39 my-machine kernel: BTRFS info (device sdb1): forced readonly

At the beginning, btrfs check gave the following output:

$ sudo btrfsck /dev/sdb1

Checking filesystem on /dev/sdb1

UUID: a69162a3-aeb3-43c0-b74d-cfd280bfa8b6

checking extents

bad block 253655810048

ERROR: errors found in extent allocation tree or chunk allocation

checking free space cache

checking fs roots

checking csums

there are no extents for csum range 563128786944-564280360960

csum exists for 563128786944-564280377344 but there is no extent record

there are no extents for csum range 566428172288-567179472896

Right section didn't have a record

there are no extents for csum range 565354430464-567179472896

Right section didn't have a record

there are no extents for csum range 564280688640-567179472896

Right section didn't have a record

there are no extents for csum range 564280639488-567179472896

csum exists for 564280639488-567179472896 but there is no extent record

ERROR: errors found in csum tree

found 1681395552256 bytes used, error(s) found

total csum bytes: 0

total tree bytes: 2406924288

total fs tree bytes: 2279718912

total extent tree bytes: 123813888

btree space waste bytes: 350386565

file data blocks allocated: 1685019078656

 referenced 1685018304512

I ran btrfs scrub, but it interrupted itself sometimes (I had to re-mount the drive then):

$ sudo btrfs scrub start -B /mnt/hd

ERROR: scrubbing /mnt/hd failed for device id 1: ret=-1, errno=5 (Input/output error)

scrub canceled for a69162a3-aeb3-43c0-b74d-cfd280bfa8b6

  scrub started at Wed Jan 23 21:26:28 2019 and was aborted after 00:45:20

  total bytes scrubbed: 509.99GiB with 0 errors

Using btrfs scrub resume, it did seem to finish, though:

$ sudo btrfs scrub status /mnt/hd

scrub status for a69162a3-aeb3-43c0-b74d-cfd280bfa8b6

  scrub resumed at Wed Jan 23 22:24:05 2019 and finished after 01:52:15

  total bytes scrubbed: 1.20TiB with 27163 errors

  error details: csum=27163

  corrected errors: 0, uncorrectable errors: 27163, unverified errors: 0

Before the ongoing run of btrfs scrub, I also tried btrfs check --repair once. That didn’t seem to change much, although subsequent runs of btrfs check showed “bad block 253432905728” instead of “bad block 253655810048”. Now, after the btrfs scrub has finished, btrfs check says

Checking filesystem on /dev/sdb1

UUID: a69162a3-aeb3-43c0-b74d-cfd280bfa8b6

checking extents

bad block 253432905728

ERROR: errors found in extent allocation tree or chunk allocation

checking free space cache

block group 253432430592 has wrong amount of free space, free space cache has 253722624 block group has 253689856

ERROR: free space cache has more free space than block group item, this could leads to serious corruption, please contact btrfs developers

failed to load free space cache for block group 253432430592

ERROR: errors found in free space cache

found 1681395535872 bytes used, error(s) found

total csum bytes: 0

total tree bytes: 2406203392

total fs tree bytes: 2279718912

total extent tree bytes: 123797504

btree space waste bytes: 350047303

file data blocks allocated: 1685019078656

 referenced 1685018304512

This seems very worrisome! How did this happen? Did the filesystem just get really messed up somehow? Or is the drive failing (it’s not old and hasn’t been heavily used at all; SMART doesn’t seem to indicate anything problematic)?