On 2021/4/8 下午4:16, Joe Hermaszewski wrote:
It took a while but I managed to get hold of another one of these
arm32 boards. Very disappointingly this exact "bitflip" is still
present (log enclosed).
Yeah, we got to the conclusion it's not bitflip, but completely 32bit
limit on armv7.
For ARMv7, it's a 32bit system, where unsigned long is only 32bit.
This means, things like page->index is only 32bit long, and for 4K page
size, it also means all filesystems (not only btrfs) can only utilize at
most 16T bytes.
But there is pitfall for btrfs, btrfs uses its internal address space
for its meatadata, and the address space is U64.
And furthermore, for btrfs it can have metadata at bytenr way larger
than the total device size.
This is possible because btrfs maps part of its address space to real
disks, thus it can have bytenr way larger than device size.
But this brings to a problem, 32bit Linux can only handle 16T, but in
your case, some of your metadata is already beyond 16T in btrfs address
space.
Then a lot of things are going to be wrong.
I have submitted a patch to do extra check, at least allowing user to
know this is the limit of 32bit:
https://patchwork.kernel.org/project/linux-btrfs/patch/20210225011814.24009-1-...@suse.com/
Unfortunately, this will not help existing fs though.
Thanks,
Qu
To summarise, as it's been a while:
- When running scrub, a "page_start" and "eb_start" mismatch is
detected (off by a single bit).
- `btrfs check` reports no significant errors on aarch64 or arm32.
- `btrfs scrub` completes successfully on aarch64!
- Now, I can confirm that `btrfs scrub` fails in the same manner on
two arm32 machines.
Not really sure where to go from here. The only things I can think of are:
- Bug in `btrfs scrub` on arm32 (seems unlikely given the single-bit
error here).
- A bitflip on the original machine wrote bad data to the disk, and
somehow only the arm32 implementation catches this...
I can give a newer kernel a try (I'm on 5.4.80 at the moment) I suppose
Best,
Joe
```
$ dmesg
[ 258.791966] BTRFS info (device sda1): scrub: started on devid 4
[ 258.792030] BTRFS info (device sda1): scrub: started on devid 1
the magic generation gap you mention is
15, I'm more suspicious about me
[ 258.792062] BTRFS info (device sda1): scrub: started on devid 2
[ 411.849669] ------------[ cut here ]------------
[ 411.849786] WARNING: CPU: 0 PID: 218 at fs/btrfs/disk-io.c:531
btree_csum_one_bio+0x22c/0x278 [btrfs]
[ 411.849789] Modules linked in: cfg80211 rfkill 8021q ip6table_nat
iptable_nat nf_nat xt_conntrack nf_conntrack nf_defrag_ipv6
nf_defrag_ipv4 ip6t_rpfilter ipt_rpfilter ip6table_raw iptable_raw
xt_pkttype nf_log_ipv6 nf_log_ipv4 nf_log_common xt_LOG xt_tcpudp
ip6table_filter ip6_tables iptable_filter phy_generic uio_pdrv_genirq
uio sch_fq_codel loop tun tap macvlan bridge stp llc lm75 ip_tables
x_tables autofs4 dm_mod dax btrfs libcrc32c xor raid6_pq
[ 411.849836] CPU: 0 PID: 218 Comm: btrfs-transacti Not tainted 5.4.80 #1-NixOS
[ 411.849838] Hardware name: Marvell Armada 380/385 (Device Tree)
[ 411.849840] Backtrace:
[ 411.849850] [<c010f698>] (dump_backtrace) from [<c010f938>]
(show_stack+0x20/0x24)
[ 411.849855] r7:00000213 r6:600f0013 r5:00000000 r4:c0f8c0c4
[ 411.849861] [<c010f918>] (show_stack) from [<c0a1bb28>]
(dump_stack+0x98/0xac)
[ 411.849866] [<c0a1ba90>] (dump_stack) from [<c012a998>] (__warn+0xe0/0x108)
[ 411.849870] r7:00000213 r6:bf058f4c r5:00000009 r4:bf120990
[ 411.849875] [<c012a8b8>] (__warn) from [<c012ad24>]
(warn_slowpath_fmt+0x74/0xc4)
[ 411.849878] r7:00000213 r6:bf120990 r5:00000000 r4:e1c1c000
[ 411.849936] [<c012acb4>] (warn_slowpath_fmt) from [<bf058f4c>]
(btree_csum_one_bio+0x22c/0x278 [btrfs])
[ 411.849941] r9:00000001 r8:e6afec78 r7:e1c1c000 r6:ed7f7000
r5:00001000 r4:8fd00000
[ 411.850044] [<bf058d20>] (btree_csum_one_bio [btrfs]) from
[<bf059f84>] (btree_submit_bio_hook+0xe8/0x100 [btrfs])
[ 411.850049] r10:e6afe4c0 r9:ecc57fc0 r8:ecc57f70 r7:ed7f7000
r6:00000000 r5:c1660370
[ 411.850051] r4:bf059e9c
[ 411.850154] [<bf059e9c>] (btree_submit_bio_hook [btrfs]) from
[<bf08b1ac>] (submit_one_bio+0x44/0x5c [btrfs])
[ 411.850158] r7:ef2d58ec r6:e1c1dcac r5:00000000 r4:bf059e9c
[ 411.850260] [<bf08b168>] (submit_one_bio [btrfs]) from [<bf096664>]
(btree_write_cache_pages+0x380/0x408 [btrfs])
[ 411.850263] r5:00000000 r4:00000000
[ 411.850366] [<bf0962e4>] (btree_write_cache_pages [btrfs]) from
[<bf0590b8>] (btree_writepages+0x7c/0x84 [btrfs])
[ 411.850371] r10:00000001 r9:8fd00000 r8:c0280bcc r7:e1c1c000
r6:e1c1dd80 r5:ecc57f70
[ 411.850373] r4:e1c1dd80
[ 411.850428] [<bf05903c>] (btree_writepages [btrfs]) from
[<c0284680>] (do_writepages+0x58/0xf4)
[ 411.850431] r5:ecc57f70 r4:ecc57e68
[ 411.850439] [<c0284628>] (do_writepages) from [<c0278b68>]
(__filemap_fdatawrite_range+0xf8/0x130)
[ 411.850442] r8:ecc57f70 r7:00001000 r6:8fd0bfff r5:e1c1c000 r4:ecc57e68
[ 411.850448] [<c0278a70>] (__filemap_fdatawrite_range) from
[<c0278cf0>] (filemap_fdatawrite_range+0x2c/0x34)
[ 411.850452] r10:ecc57f70 r9:00001000 r8:8fd0bfff r7:e1c1de4c
r6:e0202428 r5:00001000
[ 411.850454] r4:8fd0bfff
[ 411.850509] [<c0278cc4>] (filemap_fdatawrite_range) from
[<bf060544>] (btrfs_write_marked_extents+0x9c/0x1b0 [btrfs])
[ 411.850512] r5:00000001 r4:00000000
[ 411.850615] [<bf0604a8>] (btrfs_write_marked_extents [btrfs]) from
[<bf0606f0>] (btrfs_write_and_wait_transaction+0x54/0xa4 [btrfs])
[ 411.850620] r10:e1c1c000 r9:ed7f7010 r8:ed7f7000 r7:e0202428
r6:ed7f7000 r5:e1c1c000
[ 411.850621] r4:e56433f0
[ 411.850724] [<bf06069c>] (btrfs_write_and_wait_transaction [btrfs])
from [<bf062428>] (btrfs_commit_transaction+0x75c/0xc94 [btrfs])
[ 411.850728] r8:ed7f7418 r7:e0202400 r6:ed7f7000 r5:e56433f0 r4:00000000
[ 411.850831] [<bf061ccc>] (btrfs_commit_transaction [btrfs]) from
[<bf05cd98>] (transaction_kthread+0x19c/0x1e0 [btrfs])
[ 411.850836] r10:ed7f728c r9:00000000 r8:001abf6a r7:00000064
r6:ed7f7414 r5:00000bb8
[ 411.850838] r4:ed7f7000
[ 411.850893] [<bf05cbfc>] (transaction_kthread [btrfs]) from
[<c014fab4>] (kthread+0x170/0x174)
[ 411.850898] r10:ecbddbfc r9:bf05cbfc r8:ed669800 r7:e1c1c000
r6:00000000 r5:ed560d40
[ 411.850899] r4:ed54eb00
[ 411.850904] [<c014f944>] (kthread) from [<c01010e8>]
(ret_from_fork+0x14/0x2c)
[ 411.850907] Exception stack(0xe1c1dfb0 to 0xe1c1dff8)
[ 411.850911] dfa0: 00000000
00000000 00000000 00000000
[ 411.850915] dfc0: 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000
[ 411.850919] dfe0: 00000000 00000000 00000000 00000000 00000013 00000000
[ 411.850923] r10:00000000 r9:00000000 r8:00000000 r7:00000000
r6:00000000 r5:c014f944
[ 411.850925] r4:ed560d40
[ 411.850976] ---[ end trace 1bbf4c394bd7fb26 ]---
[ 411.850986] BTRFS warning (device sda1): page_start and eb_start
mismatch, eb_start=17594598817792 page_start=2412773376
[ 411.857914] BTRFS: error (device sda1) in
btrfs_commit_transaction:2279: errno=-5 IO failure (Error while
writing out transaction)
[ 411.869764] BTRFS info (device sda1): forced readonly
[ 411.869772] BTRFS warning (device sda1): Skipping commit of aborted
transaction.
[ 411.869778] BTRFS: error (device sda1) in cleanup_transaction:1832:
errno=-5 IO failure
[ 411.877843] BTRFS info (device sda1): delayed_refs has NO entry
[ 411.878076] BTRFS warning (device sda1): Skipping commit of aborted
transaction.
[ 411.882940] BTRFS warning (device sda1): failed setting block group ro: -30
[ 411.882956] BTRFS info (device sda1): scrub: not finished on devid
3 with status: -30
[ 411.883030] BTRFS warning (device sda1): failed setting block group ro: -30
[ 411.883039] BTRFS info (device sda1): scrub: not finished on devid
4 with status: -30
[ 411.883104] BTRFS warning (device sda1): failed setting block group ro: -30
[ 411.883116] BTRFS info (device sda1): scrub: not finished on devid
1 with status: -30
[ 411.883191] BTRFS warning (device sda1): failed setting block group ro: -30
[ 411.883200] BTRFS info (device sda1): scrub: not finished on devid
2 with status: -30
[ 411.953186] BTRFS info (device sda1): delayed_refs has NO entry
[ 576.361548] BTRFS critical (device sda1): unable to find logical
2412789760 length 4096
[ 576.369639] BTRFS critical (device sda1): unable to find logical
2412789760 length 4096
[ 576.378477] BTRFS critical (device sda1): unable to find logical
2412789760 length 4096
[ 576.386936] BTRFS critical (device sda1): unable to find logical
2412789760 length 4096
[ 576.395093] BTRFS critical (device sda1): unable to find logical
2412789760 length 4096
[ 576.396830] BTRFS error (device sda1): parent transid verify failed
on 12756293910528 wanted 1752939 found 1752922
[ 576.403153] BTRFS critical (device sda1): unable to find logical
2412789760 length 4096
[ 576.450091] BTRFS error (device sda1): parent transid verify failed
on 12756293910528 wanted 1752939 found 1752922
[ 576.462821] BTRFS error (device sda1): parent transid verify failed
on 12756293910528 wanted 1752939 found 1752922
[ 576.474987] BTRFS error (device sda1): parent transid verify failed
on 12756293910528 wanted 1752939 found 1752922
[ 576.486882] BTRFS error (device sda1): parent transid verify failed
on 12756293910528 wanted 1752939 found 1752922
[ 576.497905] BTRFS error (device sda1): parent transid verify failed
on 12756293910528 wanted 1752939 found 1752922
[ 576.824673] BTRFS error (device sda1): parent transid verify failed
on 12756293910528 wanted 1752939 found 1752922
[ 576.838414] BTRFS error (device sda1): parent transid verify failed
on 12756293910528 wanted 1752939 found 1752922
[ 577.324362] BTRFS error (device sda1): parent transid verify failed
on 12756293910528 wanted 1752939 found 1752922
[ 577.337736] BTRFS error (device sda1): parent transid verify failed
on 12756293910528 wanted 1752939 found 1752922
[ 578.462271] BTRFS critical (device sda1): unable to find logical
2412789760 length 4096
[ 578.470347] BTRFS critical (device sda1): unable to find logical
2412789760 length 4096
[ 578.479476] BTRFS critical (device sda1): unable to find logical
2412789760 length 4096
[ 578.488099] BTRFS critical (device sda1): unable to find logical
2412789760 length 4096
[ 578.496793] BTRFS critical (device sda1): unable to find logical
2412789760 length 4096
[ 578.505280] BTRFS critical (device sda1): unable to find logical
2412789760 length 4096
[ 580.539117] BTRFS critical (device sda1): unable to find logical
2412789760 length 4096
[ 580.547207] BTRFS critical (device sda1): unable to find logical
2412789760 length 4096
[ 580.556371] BTRFS critical (device sda1): unable to find logical
2412789760 length 4096
[ 580.564922] BTRFS critical (device sda1): unable to find logical
2412789760 length 4096
[ 580.573356] BTRFS critical (device sda1): unable to find logical
2412789760 length 4096
[ 580.581573] BTRFS critical (device sda1): unable to find logical
2412789760 length 4096
[ 581.427776] verify_parent_transid: 28 callbacks suppressed
... many more of these
```
On Sun, Dec 20, 2020 at 8:30 AM Qu Wenruo <quwenruo.bt...@gmx.com> wrote:
On 2020/12/19 下午6:35, Joe Hermaszewski wrote:
Ok, so I managed to get hold of a 64bit machine on which to run btrfs
check. `btrfs check` returns exactly the same output as the armv7 box
(no serious problems) which I suppose is good. `btrfs scrub` also
finds no problems. Boring Logs below.
What I don't quite understand is how the scrub problem on armv7l is so
reliable when it's not persisted on the disks, is the same physical
memory location being used for this breaking value, or is it perhaps a
specific pattern of data on the bus which causes this?
If it's so reliably reproducible, then I guess that would be the case,
either a specific memory range has the problem, or a specific pattern on
the bus causing the problem.
If it's the former, how easy would it be to find this broken location
and blacklist it? If it's the latter then I guess there's no hope but
to try replacing the psu/machine.
The machine survived a couple of days of memtester (on about 95% of
the RAM) and `7z b` with no problems, *shrug*
The memtester should rule out the former case, the latter case may be
resolved by newer kernel if it's not a hardware problem but a software one.
Thanks,
Qu
Best wishes and thanks for the generous help so far.
Joe
btrfs scrub aarch64:
```
[j@nixos:~]$ sudo btrfs scrub status -d /mnt
UUID: b8f4ad49-29c8-4d19-a886-cef9c487f124
scrub device /dev/sda1 (id 1) history
Scrub started: Fri Dec 18 14:24:30 2020
Status: finished
Duration: 7:36:31
Total to scrub: 2.40TiB
Rate: 91.95MiB/s
Error summary: no errors found
scrub device /dev/sdb1 (id 2) history
Scrub started: Fri Dec 18 14:24:30 2020
Status: finished
Duration: 7:12:51
Total to scrub: 2.40TiB
Rate: 96.90MiB/s
Error summary: no errors found
scrub device /dev/sdd1 (id 3) history
Scrub started: Fri Dec 18 14:24:30 2020
Status: finished
Duration: 19:47:01
Total to scrub: 7.86TiB
Rate: 115.70MiB/s
Error summary: no errors found
scrub device /dev/sdc1 (id 4) history
Scrub started: Fri Dec 18 14:24:30 2020
Status: finished
Duration: 19:46:38
Total to scrub: 7.86TiB
Rate: 115.74MiB/s
Error summary: no errors found
```
btrfs check aarch64:
```
[nixos@nixos:/]$ sudo btrfs check --readonly /dev/sda1
Opening filesystem to check...
Checking filesystem on /dev/sda1
UUID: b8f4ad49-29c8-4d19-a886-cef9c487f124
[1/7] checking root items
[2/7] checking extents
[3/7] checking free space cache
[4/7] checking fs roots
root 294 inode 24665 errors 100, file extent discount
Found file extent holes:
start: 3709534208, len: 163840
root 294 inode 406548 errors 100, file extent discount
Found file extent holes:
start: 98729984, len: 720896
ERROR: errors found in fs roots
found 11280701063168 bytes used, error(s) found
total csum bytes: 10937464120
total tree bytes: 18538053632
total fs tree bytes: 5877579776
total extent tree bytes: 534052864
btree space waste bytes: 2316660292
file data blocks allocated: 17244587220992
referenced 14211684794368%
```
On Sat, Nov 28, 2020 at 8:46 AM Qu Wenruo <quwenruo.bt...@gmx.com> wrote:
On 2020/11/27 下午11:15, Joe Hermaszewski wrote:
Hi Qu,
Thanks for the patch. I recompiled the kernel ran the scrub and your
patch worked as expected, here is the log:
```
[ 337.365239] BTRFS info (device sda1): scrub: started on devid 2
[ 337.366283] BTRFS info (device sda1): scrub: started on devid 1
[ 337.402822] BTRFS info (device sda1): scrub: started on devid 3
[ 337.411944] BTRFS info (device sda1): scrub: started on devid 4
[ 471.997496] ------------[ cut here ]------------
[ 471.997614] WARNING: CPU: 0 PID: 218 at fs/btrfs/disk-io.c:531
btree_csum_one_bio+0x22c/0x278 [btrfs]
[ 471.997616] Modules linked in: cfg80211 rfkill 8021q ip6table_nat
iptable_nat nf_nat ftdi_sio phy_generic usbserial xt_conntrack
nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 ip6t_rpfilter ipt_rpfilter
ip6table_raw uio_pdrv_genirq iptable_raw uio xt_pkttype nf_log_ipv6
nf_log_ipv4 nf_log_common xt_LOG xt_tcpudp ip6table_filter ip6_tables
iptable_filter sch_fq_codel loop tun tap macvlan bridge stp llc lm75
ip_tables x_tables autofs4 dm_mod dax btrfs libcrc32c xor raid6_pq
[ 471.997666] CPU: 0 PID: 218 Comm: btrfs-transacti Not tainted 5.4.78 #1-NixOS
[ 471.997668] Hardware name: Marvell Armada 380/385 (Device Tree)
[ 471.997669] Backtrace:
[ 471.997680] [<c010f698>] (dump_backtrace) from [<c010f938>]
(show_stack+0x20/0x24)
[ 471.997684] r7:00000213 r6:600c0013 r5:00000000 r4:c0f8c044
[ 471.997691] [<c010f918>] (show_stack) from [<c0a1b848>]
(dump_stack+0x98/0xac)
[ 471.997696] [<c0a1b7b0>] (dump_stack) from [<c012a998>] (__warn+0xe0/0x108)
[ 471.997700] r7:00000213 r6:bf058f4c r5:00000009 r4:bf120990
[ 471.997704] [<c012a8b8>] (__warn) from [<c012ad24>]
(warn_slowpath_fmt+0x74/0xc4)
[ 471.997707] r7:00000213 r6:bf120990 r5:00000000 r4:e1822000
[ 471.997765] [<c012acb4>] (warn_slowpath_fmt) from [<bf058f4c>]
(btree_csum_one_bio+0x22c/0x278 [btrfs])
[ 471.997770] r9:00000001 r8:c10decb8 r7:e1822000 r6:ed66b000
r5:00001000 r4:4fd00000
[ 471.997872] [<bf058d20>] (btree_csum_one_bio [btrfs]) from
[<bf059f84>] (btree_submit_bio_hook+0xe8/0x100 [btrfs])
[ 471.997877] r10:e2197b48 r9:ec845fc0 r8:ec845f70 r7:ed66b000
r6:00000000 r5:e2b74af0
[ 471.997879] r4:bf059e9c
[ 471.997981] [<bf059e9c>] (btree_submit_bio_hook [btrfs]) from
[<bf08b1ac>] (submit_one_bio+0x44/0x5c [btrfs])
[ 471.997985] r7:ef3724d4 r6:e1823cac r5:00000000 r4:bf059e9c
[ 471.998087] [<bf08b168>] (submit_one_bio [btrfs]) from [<bf096664>]
(btree_write_cache_pages+0x380/0x408 [btrfs])
[ 471.998090] r5:00000000 r4:00000000
[ 471.998193] [<bf0962e4>] (btree_write_cache_pages [btrfs]) from
[<bf0590b8>] (btree_writepages+0x7c/0x84 [btrfs])
[ 471.998197] r10:00000001 r9:4fd00000 r8:c0280d14 r7:e1822000
r6:e1823d80 r5:ec845f70
[ 471.998199] r4:e1823d80
[ 471.998255] [<bf05903c>] (btree_writepages [btrfs]) from
[<c02847c8>] (do_writepages+0x58/0xf4)
[ 471.998258] r5:ec845f70 r4:ec845e68
[ 471.998266] [<c0284770>] (do_writepages) from [<c0278cb0>]
(__filemap_fdatawrite_range+0xf8/0x130)
[ 471.998270] r8:ec845f70 r7:00001000 r6:4fd0bfff r5:e1822000 r4:ec845e68
[ 471.998275] [<c0278bb8>] (__filemap_fdatawrite_range) from
[<c0278e38>] (filemap_fdatawrite_range+0x2c/0x34)
[ 471.998279] r10:ec845f70 r9:00001000 r8:4fd0bfff r7:e1823e4c
r6:c1955e28 r5:00001000
[ 471.998281] r4:4fd0bfff
[ 471.998335] [<c0278e0c>] (filemap_fdatawrite_range) from
[<bf060544>] (btrfs_write_marked_extents+0x9c/0x1b0 [btrfs])
[ 471.998338] r5:00000001 r4:00000000
[ 471.998441] [<bf0604a8>] (btrfs_write_marked_extents [btrfs]) from
[<bf0606f0>] (btrfs_write_and_wait_transaction+0x54/0xa4 [btrfs])
[ 471.998446] r10:e1822000 r9:ed66b010 r8:ed66b000 r7:c1955e28
r6:ed66b000 r5:e1822000
[ 471.998447] r4:eddc4f30
[ 471.998551] [<bf06069c>] (btrfs_write_and_wait_transaction [btrfs])
from [<bf062428>] (btrfs_commit_transaction+0x75c/0xc94 [btrfs])
[ 471.998555] r8:ed66b418 r7:c1955e00 r6:ed66b000 r5:eddc4f30 r4:00000000
[ 471.998658] [<bf061ccc>] (btrfs_commit_transaction [btrfs]) from
[<bf05cd98>] (transaction_kthread+0x19c/0x1e0 [btrfs])
[ 471.998663] r10:ed66b28c r9:00000000 r8:001aab57 r7:00000064
r6:ed66b414 r5:00000bb8
[ 471.998664] r4:ed66b000
[ 471.998719] [<bf05cbfc>] (transaction_kthread [btrfs]) from
[<c014facc>] (kthread+0x170/0x174)
[ 471.998724] r10:ed765bfc r9:bf05cbfc r8:ed56a000 r7:e1822000
r6:00000000 r5:ed5c8600
[ 471.998726] r4:ed5c8740
[ 471.998731] [<c014f95c>] (kthread) from [<c01010e8>]
(ret_from_fork+0x14/0x2c)
[ 471.998733] Exception stack(0xe1823fb0 to 0xe1823ff8)
[ 471.998737] 3fa0: 00000000
00000000 00000000 00000000
[ 471.998741] 3fc0: 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000
[ 471.998745] 3fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[ 471.998749] r10:00000000 r9:00000000 r8:00000000 r7:00000000
r6:00000000 r5:c014f95c
[ 471.998751] r4:ed5c8600
[ 471.998820] ---[ end trace 6a9fb9f547659a4d ]---
[ 471.998855] BTRFS warning (device sda1): page_start and eb_start
mismatch, eb_start=17593525075968 page_start=1339031552
[ 472.015514] BTRFS: error (device sda1) in
btrfs_commit_transaction:2279: errno=-5 IO failure (Error while
writing out transaction)
[ 472.027321] BTRFS info (device sda1): forced readonly
[ 472.027326] BTRFS warning (device sda1): Skipping commit of aborted
transaction.
[ 472.027330] BTRFS: error (device sda1) in cleanup_transaction:1832:
errno=-5 IO failure
[ 472.035378] BTRFS info (device sda1): delayed_refs has NO entry
[ 472.039102] BTRFS warning (device sda1): failed setting block group ro: -30
[ 472.039107] BTRFS info (device sda1): scrub: not finished on devid
3 with status: -30
[ 472.039114] BTRFS info (device sda1): scrub: not finished on devid
4 with status: -30
[ 472.039227] BTRFS warning (device sda1): failed setting block group ro: -30
[ 472.039230] BTRFS warning (device sda1): failed setting block group ro: -30
[ 472.039237] BTRFS info (device sda1): scrub: not finished on devid
2 with status: -30
[ 472.039243] BTRFS info (device sda1): scrub: not finished on devid
1 with status: -30
```
To rob you of the suspense:
printf "0x%016x\n" (17593525075968 - 1339031552)
0x0000100000000000
Very surprising considering that this machine has ECC ram!
ARMv7 with ECC, and we still had such bitflip!?
I guess everything is possible in 2020.
What would you recommend as a fix?
It's a hardware problem, I really don't have any recommendation at all.
I guess you may want to request an RMA?
Thanks,
Qu
Best,
Joe
On Thu, Nov 26, 2020 at 7:05 PM Qu Wenruo <quwenruo.bt...@gmx.com> wrote:
On 2020/11/26 下午6:53, Joe Hermaszewski wrote:
Hi Qu,
This is the output of btrfs check with the device unmounted:
```
[root@nixos:~]# btrfs check --readonly /dev/sda1
Opening filesystem to check...
Checking filesystem on /dev/sda1
UUID: b8f4ad49-29c8-4d19-a886-cef9c487f124
[1/7] checking root items
[2/7] checking extents
[3/7] checking free space cache
[4/7] checking fs roots
root 294 inode 24665 errors 100, file extent discount
Found file extent holes:
start: 3709534208, len: 163840
root 294 inode 406548 errors 100, file extent discount
Found file extent holes:
start: 0, len: 99450880
ERROR: errors found in fs roots
found 11279251902464 bytes used, error(s) found
total csum bytes: 10935906504
total tree bytes: 18455740416
total fs tree bytes: 5798936576
total extent tree bytes: 532250624
btree space waste bytes: 2308849707
file data blocks allocated: 17243418611712
referenced 14210256932864
```
Looks the same as before...
Then it means, at least your metadata is pretty safe. Nothing really
needs to be worried (so far).
This also means, the problem only happens at runtime, not something on-disk.
If you are OK to re-compile the kernel, and the warning message is
always the same at line number 531 of disk-io.c, then I recommend the
attached debug diff
The diff will output the found_start (from eb) and page_start (from page).
If it's memory bitflip, we should have a pretty signature diff at the
output.
If not memory bitflip, then we really have a bug to dig.
I'm afraid I don't have the precise details of the transid error
saved. I think I meant to write earlier that the message that comes up
now and then is the "errno=-5 IO failure (Error while writing out
transaction)". I've not seen the transid mismatch one since the first
incident, sorry for that slip-up.
I'll try and attach to a known good system, will I have to attach the
whole array because I don't think I have that many enclosures for the
drives.
You only need to mount the fs you're seeing the problem.
But if that fs is on multiple devices, then I guess you need to mount
them all.
Thanks,
Qu
I'll also run a memtest on this box.
Thank you for the helpful response.
Best,
Joe
On Thu, Nov 26, 2020 at 2:15 PM Qu Wenruo <quwenruo.bt...@gmx.com> wrote:
On 2020/11/25 下午11:28, Joe Hermaszewski wrote:
Hi,
I have a arm32 machine with four drives with a btrfs fs spanning then in RAID1.
The filesystem has started behaving badly recently and I'm writing to:
- Solicit advice on how best to get the system back to a stable state
- Report a potential bug
## What happened:
A couple of days ago I could no longer ssh into it, and on the serial
connection there were heaps of messages (and new ones appearing with great
frequency) along the lines of: `parent transid verify failed on blah... wanted
x got y`.
Although I don't have a record of the precise messages I do remember that there
was a difference of `15` between x and y.
This normally can be a sign of unreliable HDD, which lies on FLUSH,
killing metadata COW.
But, your btrfs check doesn't report the same problem, thus I'm confused.
Would you please try to run a "btrfs check --readonly /dev/sda1" with
the fs unmounted?
And, would you provide the full dmesg of that mismatch?
The reason for the exact number is, I'm suspecting hardware memory
corruption.
I power-cycled system and started a scrub after it rebooted, this was
interrupted quite promptly by several more errors in btrfs, and the disk
remounted RO.
Every now and then in the kernel log I get messages like:
`parent transid verify failed on blah... wanted x got y`
Not showing up in the gist dmesg though.
## Important info
The dev stats are all zero.
Here are the outputs of some btrfs commands, dmesg and the kernel log from the
previous two boots: https://gist.github.com/b1beab134403c5047e2efbceb98985f9
The "cut here" portion of the kernel log is as follows
```
[ 409.158097] ------------[ cut here ]------------
[ 409.158205] WARNING: CPU: 1 PID: 217 at fs/btrfs/disk-io.c:531
btree_csum_one_bio+0x208/0x248 [btrfs]
The line number shows, the tree bytenr doesn't match with the one in memory.
This is really too rare to be seen, especially when we have no other
error reported from btrfs (at least in the gist)
Since there is no other problems showing up in the gist, it means it
could be a bit flip, considering the magic generation gap you mention is
15, I'm more suspicious about memory bit flip.
If you can provide the full parent transid mismatch error message, it
may help to determine the possibility of hardware memory corruption.
Thanks,
Qu
[ 409.158208] Modules linked in: cfg80211 rfkill 8021q ip6table_nat
iptable_nat nf_nat xt_conntrack nf_conntrack nf_defrag_ipv6
nf_defrag_ipv4 ip6t_rpfilter ipt_rpfilter ip6table_raw iptable_raw
xt_pkttype nf_log_ipv6 nf_log_ipv4 nf_log_common xt_LOG xt_tcpudp
ftdi_sio usbserial phy_generic uio_pdrv_genirq uio ip6table_filter
ip6_tables iptable_filter sch_fq_codel loop tun tap macvlan bridge stp
llc lm75 ip_tables x_tables autofs4 dm_mod dax btrfs libcrc32c xor
raid6_pq
[ 409.158258] CPU: 1 PID: 217 Comm: btrfs-transacti Not tainted 5.4.77 #1-NixOS
[ 409.158260] Hardware name: Marvell Armada 380/385 (Device Tree)
[ 409.158261] Backtrace:
[ 409.158272] [<c010f698>] (dump_backtrace) from [<c010f938>]
(show_stack+0x20/0x24)
[ 409.158277] r7:00000213 r6:600f0013 r5:00000000 r4:c0f8c044
[ 409.158283] [<c010f918>] (show_stack) from [<c0a1b388>]
(dump_stack+0x98/0xac)
[ 409.158288] [<c0a1b2f0>] (dump_stack) from [<c012a998>] (__warn+0xe0/0x108)
[ 409.158292] r7:00000213 r6:bf058ec8 r5:00000009 r4:bf120990
[ 409.158296] [<c012a8b8>] (__warn) from [<c012ad24>]
(warn_slowpath_fmt+0x74/0xc4)
[ 409.158300] r7:00000213 r6:bf120990 r5:00000000 r4:e2392000
[ 409.158358] [<c012acb4>] (warn_slowpath_fmt) from [<bf058ec8>]
(btree_csum_one_bio+0x208/0x248 [btrfs])
[ 409.158363] r9:e277abe0 r8:00000001 r7:e2392000 r6:ea3d17f0
r5:00000000 r4:eefd2d3c
[ 409.158465] [<bf058cc0>] (btree_csum_one_bio [btrfs]) from
[<bf059ef4>] (btree_submit_bio_hook+0xe8/0x100 [btrfs])
[ 409.158470] r10:e32ce170 r9:ecc45fc0 r8:ecc45f70 r7:ec82b000
r6:00000000 r5:ea3d17f0
[ 409.158472] r4:bf059e0c
[ 409.158575] [<bf059e0c>] (btree_submit_bio_hook [btrfs]) from
[<bf08b11c>] (submit_one_bio+0x44/0x5c [btrfs])
[ 409.158578] r7:ef36c048 r6:e2393cac r5:00000000 r4:bf059e0c
[ 409.158683] [<bf08b0d8>] (submit_one_bio [btrfs]) from [<bf0965d4>]
(btree_write_cache_pages+0x380/0x408 [btrfs])
[ 409.158686] r5:00000000 r4:00000000
[ 409.158788] [<bf096254>] (btree_write_cache_pages [btrfs]) from
[<bf059028>] (btree_writepages+0x7c/0x84 [btrfs])
[ 409.158793] r10:00000001 r9:4fd00000 r8:c0280c94 r7:e2392000
r6:e2393d80 r5:ecc45f70
[ 409.158794] r4:e2393d80
[ 409.158850] [<bf058fac>] (btree_writepages [btrfs]) from
[<c0284748>] (do_writepages+0x58/0xf4)
[ 409.158852] r5:ecc45f70 r4:ecc45e68
[ 409.158860] [<c02846f0>] (do_writepages) from [<c0278c30>]
(__filemap_fdatawrite_range+0xf8/0x130)
[ 409.158864] r8:ecc45f70 r7:00001000 r6:4fd0bfff r5:e2392000 r4:ecc45e68
[ 409.158869] [<c0278b38>] (__filemap_fdatawrite_range) from
[<c0278db8>] (filemap_fdatawrite_range+0x2c/0x34)
[ 409.158874] r10:ecc45f70 r9:00001000 r8:4fd0bfff r7:e2393e4c
r6:c73bc628 r5:00001000
[ 409.158875] r4:4fd0bfff
[ 409.158929] [<c0278d8c>] (filemap_fdatawrite_range) from
[<bf0604b4>] (btrfs_write_marked_extents+0x9c/0x1b0 [btrfs])
[ 409.158931] r5:00000001 r4:00000000
[ 409.159033] [<bf060418>] (btrfs_write_marked_extents [btrfs]) from
[<bf060660>] (btrfs_write_and_wait_transaction+0x54/0xa4 [btrfs])
[ 409.159038] r10:e2392000 r9:ec82b010 r8:ec82b000 r7:c73bc628
r6:ec82b000 r5:e2392000
[ 409.159040] r4:c8b81ca8
[ 409.159141] [<bf06060c>] (btrfs_write_and_wait_transaction [btrfs])
from [<bf062398>] (btrfs_commit_transaction+0x75c/0xc94 [btrfs])
[ 409.159145] r8:ec82b418 r7:c73bc600 r6:ec82b000 r5:c8b81ca8 r4:00000000
[ 409.159248] [<bf061c3c>] (btrfs_commit_transaction [btrfs]) from
[<bf05cd08>] (transaction_kthread+0x19c/0x1e0 [btrfs])
[ 409.159253] r10:ec82b28c r9:00000000 r8:001aaafa r7:00000064
r6:ec82b414 r5:00000bb8
[ 409.159254] r4:ec82b000
[ 409.159309] [<bf05cb6c>] (transaction_kthread [btrfs]) from
[<c014fabc>] (kthread+0x170/0x174)
[ 409.159313] r10:eca87bfc r9:bf05cb6c r8:ed619000 r7:e2392000
r6:00000000 r5:ed5ee700
[ 409.159315] r4:ed5ee1c0
[ 409.159320] [<c014f94c>] (kthread) from [<c01010e8>]
(ret_from_fork+0x14/0x2c)
[ 409.159322] Exception stack(0xe2393fb0 to 0xe2393ff8)
[ 409.159326] 3fa0: 00000000
00000000 00000000 00000000
[ 409.159331] 3fc0: 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000
[ 409.159334] 3fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[ 409.159338] r10:00000000 r9:00000000 r8:00000000 r7:00000000
r6:00000000 r5:c014f94c
[ 409.159340] r4:ed5ee700
[ 409.159342] ---[ end trace eea59ced12fa7859 ]---
[ 409.165084] BTRFS: error (device sda1) in
btrfs_commit_transaction:2279: errno=-5 IO failure (Error while
writing out transaction)
[ 409.176920] BTRFS info (device sda1): forced readonly
[ 409.176947] BTRFS warning (device sda1): Skipping commit of aborted
transaction.
[ 409.176952] BTRFS: error (device sda1) in cleanup_transaction:1832:
errno=-5 IO failure
[ 409.185049] BTRFS info (device sda1): delayed_refs has NO entry
[ 409.310199] BTRFS info (device sda1): scrub: not finished on devid
3 with status: -125
[ 409.664880] BTRFS info (device sda1): scrub: not finished on devid
4 with status: -125
[ 410.106791] BTRFS info (device sda1): scrub: not finished on devid
1 with status: -125
[ 411.268585] BTRFS warning (device sda1): failed setting block group ro: -30
[ 411.268594] BTRFS info (device sda1): scrub: not finished on devid
2 with status: -30
[ 411.268605] BTRFS info (device sda1): delayed_refs has NO entry
```
Information requested here
(https://btrfs.wiki.kernel.org/index.php/Btrfs_mailing_list):
```
$ uname -a
Linux thanos 5.4.77 #1-NixOS SMP Tue Nov 10 20:13:20 UTC 2020 armv7l GNU/Linux
$ btrfs --version
btrfs-progs v5.7
$ sudo btrfs fi show
Label: none uuid: b8f4ad49-29c8-4d19-a886-cef9c487f124
Total devices 4 FS bytes used 10.26TiB
devid 1 size 3.64TiB used 2.40TiB path /dev/sda1
devid 2 size 3.64TiB used 2.40TiB path /dev/sdc1
devid 3 size 9.09TiB used 7.86TiB path /dev/sdd1
devid 4 size 9.09TiB used 7.86TiB path /dev/sdb1
Label: none uuid: d02a3067-0a23-4c1f-96ac-80dbc26622f2
Total devices 1 FS bytes used 116.35MiB
devid 1 size 399.82MiB used 224.00MiB path /dev/sda2
$ sudo btrfs fi df /
Data, RAID1: total=10.25TiB, used=10.24TiB
System, RAID1: total=64.00MiB, used=1.45MiB
Metadata, RAID1: total=18.00GiB, used=17.19GiB
GlobalReserve, single: total=512.00MiB, used=0.00B
```
Thanks to demfloro and multicore on #btrfs for prompting this email.
Best wishes,
Joe
