* "Corrected" errors persist after scrubbing
@ 2017-05-06 10:33 Tom Hale
2017-05-08 19:26 ` Chris Murphy
0 siblings, 1 reply; 6+ messages in thread
From: Tom Hale @ 2017-05-06 10:33 UTC (permalink / raw)
To: linux-btrfs
[-- Attachment #1: Type: text/plain, Size: 2534 bytes --]
Below (and also attached because of formatting) is an example of `btrfs
scrub` incorrectly reporting that errors have been corrected.
In this example, /dev/md127 is the device created by running:
mdadm --build /dev/md0 --level=faulty --raid-devices=1 /dev/loop0
The filesystem is RAID1.
# mdadm --grow /dev/md0 --layout=rp400
layout for /dev/md0 set to 12803
# btrfs scrub start -Bd /mnt/tmp
scrub device /dev/md127 (id 1) done
scrub started at Fri May 5 19:23:54 2017 and finished after
00:00:01
total bytes scrubbed: 200.47MiB with 8 errors
error details: read=8
corrected errors: 8, uncorrectable errors: 0, unverified errors: 248
scrub device /dev/loop1 (id 2) done
scrub started at Fri May 5 19:23:54 2017 and finished after
00:00:01
total bytes scrubbed: 200.47MiB with 0 errors
WARNING: errors detected during scrubbing, corrected
# ### But the errors haven't really been corrected, they're still there:
# mdadm --grow /dev/md0 --layout=clear # Stop producing additional errors
layout for /dev/md0 set to 31
# btrfs scrub start -Bd /mnt/tmp
scrub device /dev/md127 (id 1) done
scrub started at Fri May 5 19:24:24 2017 and finished after
00:00:00
total bytes scrubbed: 200.47MiB with 8 errors
error details: read=8
corrected errors: 8, uncorrectable errors: 0, unverified errors: 248
scrub device /dev/loop1 (id 2) done
scrub started at Fri May 5 19:24:24 2017 and finished after
00:00:00
total bytes scrubbed: 200.47MiB with 0 errors
WARNING: errors detected during scrubbing, corrected
#
Since scrub is checking for read issues, I expect that it would read any
corrections before asserting that they have indeed been corrected.
I understand that HDDs have a pool of non-LBA-addressable sectors set
aside to mask bad physical sectors, but this pool size is fixed by the
manufacturer (who makes money from sales of new drives).
However, I don't believe it is sufficient to blindly trust that the
underlying HDD still has spare reallocatable sectors or that the
hardware will always correctly write data, given the verification and
fixing intention of scrub.
At a minimum, shouldn't these 8 "corrected errors" be listed as
"uncorrectable errors" to inform the sysadmin that data integrity has
degraded (e.g. in this RAID1 example the data is no longer duplicated)?
Ideally, I would hope that the blocks with uncorrectable errors are
marked as bad and fresh blocks are used to maintain integrity.
--
Regards,
Tom Hale
[-- Attachment #2: btrfs-scrub --]
[-- Type: text/plain, Size: 1309 bytes --]
# mdadm --grow /dev/md0 --layout=rp400
layout for /dev/md0 set to 12803
# btrfs scrub start -Bd /mnt/tmp
scrub device /dev/md127 (id 1) done
scrub started at Fri May 5 19:23:54 2017 and finished after 00:00:01
total bytes scrubbed: 200.47MiB with 8 errors
error details: read=8
corrected errors: 8, uncorrectable errors: 0, unverified errors: 248
scrub device /dev/loop1 (id 2) done
scrub started at Fri May 5 19:23:54 2017 and finished after 00:00:01
total bytes scrubbed: 200.47MiB with 0 errors
WARNING: errors detected during scrubbing, corrected
# ### But the errors haven't really been corrected, they're still there:
# mdadm --grow /dev/md0 --layout=clear # Stop producing additional errors
layout for /dev/md0 set to 31
# btrfs scrub start -Bd /mnt/tmp
scrub device /dev/md127 (id 1) done
scrub started at Fri May 5 19:24:24 2017 and finished after 00:00:00
total bytes scrubbed: 200.47MiB with 8 errors
error details: read=8
corrected errors: 8, uncorrectable errors: 0, unverified errors: 248
scrub device /dev/loop1 (id 2) done
scrub started at Fri May 5 19:24:24 2017 and finished after 00:00:00
total bytes scrubbed: 200.47MiB with 0 errors
WARNING: errors detected during scrubbing, corrected
#
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: "Corrected" errors persist after scrubbing
2017-05-06 10:33 "Corrected" errors persist after scrubbing Tom Hale
@ 2017-05-08 19:26 ` Chris Murphy
2017-05-09 5:15 ` Duncan
2017-05-16 9:53 ` Tom Hale
0 siblings, 2 replies; 6+ messages in thread
From: Chris Murphy @ 2017-05-08 19:26 UTC (permalink / raw)
To: Tom Hale; +Cc: Btrfs BTRFS
On Sat, May 6, 2017 at 4:33 AM, Tom Hale <tom@hale.ee> wrote:
> Below (and also attached because of formatting) is an example of `btrfs
> scrub` incorrectly reporting that errors have been corrected.
>
> In this example, /dev/md127 is the device created by running:
> mdadm --build /dev/md0 --level=faulty --raid-devices=1 /dev/loop0
>
> The filesystem is RAID1.
>
> # mdadm --grow /dev/md0 --layout=rp400
> layout for /dev/md0 set to 12803
> # btrfs scrub start -Bd /mnt/tmp
> scrub device /dev/md127 (id 1) done
> scrub started at Fri May 5 19:23:54 2017 and finished after
> 00:00:01
> total bytes scrubbed: 200.47MiB with 8 errors
> error details: read=8
> corrected errors: 8, uncorrectable errors: 0, unverified errors: 248
> scrub device /dev/loop1 (id 2) done
> scrub started at Fri May 5 19:23:54 2017 and finished after
> 00:00:01
> total bytes scrubbed: 200.47MiB with 0 errors
> WARNING: errors detected during scrubbing, corrected
> # ### But the errors haven't really been corrected, they're still there:
> # mdadm --grow /dev/md0 --layout=clear # Stop producing additional errors
> layout for /dev/md0 set to 31
> # btrfs scrub start -Bd /mnt/tmp
> scrub device /dev/md127 (id 1) done
> scrub started at Fri May 5 19:24:24 2017 and finished after
> 00:00:00
> total bytes scrubbed: 200.47MiB with 8 errors
> error details: read=8
> corrected errors: 8, uncorrectable errors: 0, unverified errors: 248
> scrub device /dev/loop1 (id 2) done
> scrub started at Fri May 5 19:24:24 2017 and finished after
> 00:00:00
> total bytes scrubbed: 200.47MiB with 0 errors
> WARNING: errors detected during scrubbing, corrected
> #
What are the complete kernel messages for the scrub event? This should
show what problem Btrfs detects and how it fixes it, and what sectors
it's fixing each time.
>
> Since scrub is checking for read issues, I expect that it would read any
> corrections before asserting that they have indeed been corrected.
Read errors are fixed by overwrites. If the underlying device doesn't
report an error for the write command, it's assumed to succeed. Even
md and LVM raid's do this.
>
> I understand that HDDs have a pool of non-LBA-addressable sectors set
> aside to mask bad physical sectors, but this pool size is fixed by the
> manufacturer (who makes money from sales of new drives).
>
> However, I don't believe it is sufficient to blindly trust that the
> underlying HDD still has spare reallocatable sectors or that the
> hardware will always correctly write data, given the verification and
> fixing intention of scrub.
If the is no spare, the drive by spec is supposed to report a write
error. The original sector fails write, and there are no more spares,
that means the write can only fail.
In Btrfs land, it keeps trying to write, I don't think it has a limit.
In md land, this used to be fatal, the block device would be ejected
from the array and not used anymore; but I think there's somewhat
recent patches that optionally allow a badblock map to exist for
tracking sectors that fail writes, and md simply won't use them and
will do it's own remapping.
>
> At a minimum, shouldn't these 8 "corrected errors" be listed as
> "uncorrectable errors" to inform the sysadmin that data integrity has
> degraded (e.g. in this RAID1 example the data is no longer duplicated)?
>
> Ideally, I would hope that the blocks with uncorrectable errors are
> marked as bad and fresh blocks are used to maintain integrity.
The only way they are corrected is if the Btrfs overwrite to fix bad
reads (either a csum error, or a device read error) does not result in
a device write error, then it is corrected. I haven't tried simulating
persistent write failure to see how Btrfs behaves but my recollection
is it just keeps trying and does not eject that device. Nor does it
track bad sectors.
--
Chris Murphy
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: "Corrected" errors persist after scrubbing
2017-05-08 19:26 ` Chris Murphy
@ 2017-05-09 5:15 ` Duncan
2017-05-16 9:53 ` Tom Hale
1 sibling, 0 replies; 6+ messages in thread
From: Duncan @ 2017-05-09 5:15 UTC (permalink / raw)
To: linux-btrfs
Chris Murphy posted on Mon, 08 May 2017 13:26:16 -0600 as excerpted:
> On Sat, May 6, 2017 at 4:33 AM, Tom Hale <tom@hale.ee> wrote:
>> Below (and also attached because of formatting) is an example of `btrfs
>> scrub` incorrectly reporting that errors have been corrected.
>>
>> In this example, /dev/md127 is the device created by running:
>> mdadm --build /dev/md0 --level=faulty --raid-devices=1 /dev/loop0
>>
>> The filesystem is RAID1.
>>
>> # mdadm --grow /dev/md0 --layout=rp400
>> layout for /dev/md0 set to 12803
>> # btrfs scrub start -Bd /mnt/tmp
>> scrub device /dev/md127 (id 1) done
>> scrub started at Fri May 5 19:23:54 2017 and finished after
>> 00:00:01
>> total bytes scrubbed: 200.47MiB with 8 errors
>> error details: read=8
>> corrected errors: 8, uncorrectable errors: 0, unverified errors: 248
>> scrub device /dev/loop1 (id 2) done
>> scrub started at Fri May 5 19:23:54 2017 and finished after
>> 00:00:01
>> total bytes scrubbed: 200.47MiB with 0 errors
>> WARNING: errors detected during scrubbing, corrected
>> # ### But the errors haven't really been corrected, they're still there:
>> # mdadm --grow /dev/md0 --layout=clear # Stop producing additional errors
>> layout for /dev/md0 set to 31
>> # btrfs scrub start -Bd /mnt/tmp
>> scrub device /dev/md127 (id 1) done
>> scrub started at Fri May 5 19:24:24 2017 and finished after
>> 00:00:00
>> total bytes scrubbed: 200.47MiB with 8 errors
>> error details: read=8
>> corrected errors: 8, uncorrectable errors: 0, unverified errors: 248
>> scrub device /dev/loop1 (id 2) done
>> scrub started at Fri May 5 19:24:24 2017 and finished after
>> 00:00:00
>> total bytes scrubbed: 200.47MiB with 0 errors
>> WARNING: errors detected during scrubbing, corrected
>> #
>
>
> What are the complete kernel messages for the scrub event? This should
> show what problem Btrfs detects and how it fixes it, and what sectors
> it's fixing each time.
I'm also wondering what version of kernel and btrfs-progs are being
used here. For two reasons:
First:
AFAIK newer code shouldn't report unverified, which was originally
reported for blocks where the checksums of the blocks containing the
checksums of the unverified errors were in bad blocks. IOW, the lower
branches of the tree couldn't be checked because higher ones were
still being repaired.
Back then, in ordered to fix such errors, one had to do multiple passes
manually, until there were no more unverified errors, each pass fixing
errors at one level so the levels below it could actually be checked in
the next pass.
I know because I had a pair of ssds where I deliberately kept an ssd
that was going bad in the btrfs raid1 pair, in ordered to see how things
worked over time. So I got quite some experience running and rerunning
scrubs until all the errors were corrected after multiple passes!
But newer versions catch that problem and I believe actually use the
second copy for the verifications, so as long as there's no uncorrectable,
there should be no unverified, either. (Either that or they do multiple
passes automatically, like I used to do manually. I'm not sure which
except the former should be simpler and faster so I suspect that's what's
done.)
So the fact that there's unverified errors reported hints to me that
the used versions may be old. Either that, or it's a different mechanism
generating the unverified, that I'm not familiar with and that doesn't
get corrected from the other copy or via multipass like the ones I have
experience with do. But that's why I say "hint".
Second:
AFAIK there was a short period around kernel 4.10 and early 4.11-rcs where
read-errors were indeed not being corrected properly. To my knowledge this
was in operation, not scrub, but perhaps certain scrub cases were affected
as well.
AFAIK this problem is entirely fixed in 4.11 release, and presumably in the
4.10 stables, and I don't believe 4.8 and earlier were affected at all (but
I'm not sure about 4.9, I /think/ it was before the regression, but some
4.9-stable releases /might/ be affected), but whatever the OP's running
/might/ just be in that gap, it'd take a dev or someone following those
specific patches closer than I did to know specifically what's affected
and thus be able to say for sure, if the OP's running something 4.9 or 4.10,
or early 4.11-rcs, but not the latest 4.11 release.
--
Duncan - List replies preferred. No HTML msgs.
"Every nonfree program has a lord, a master --
and if you use the program, he is your master." Richard Stallman
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: "Corrected" errors persist after scrubbing
2017-05-08 19:26 ` Chris Murphy
2017-05-09 5:15 ` Duncan
@ 2017-05-16 9:53 ` Tom Hale
2017-05-16 11:27 ` Austin S. Hemmelgarn
2017-05-16 18:55 ` Chris Murphy
1 sibling, 2 replies; 6+ messages in thread
From: Tom Hale @ 2017-05-16 9:53 UTC (permalink / raw)
To: Chris Murphy; +Cc: Btrfs BTRFS
[-- Attachment #1: Type: text/plain, Size: 5120 bytes --]
Hi Chris,
On 09/05/17 02:26, Chris Murphy wrote:
> Read errors are fixed by overwrites. If the underlying device doesn't
> report an error for the write command, it's assumed to succeed. Even
> md and LVM raid's do this.
I understand assuming writes succeed in general. However, for a tool
which says (in its usage):
"verify checksums of data and metadata"
I would expect that the tool reports the *final state* of the data:
* Because the explicit function of scrub is to verify that all data can
be read.
* In a RAID1 situation, the sysadmin could think that the there are two
valid copies of all data, when in fact there may only be one.
> What are the complete kernel messages for the scrub event? This should
> show what problem Btrfs detects and how it fixes it, and what sectors
> it's fixing each time.
Attached are the kernel logs (and the `grep fixed` version) showing the
same logical blocks are "fixed" twice.
Below (and attached because of formatting) I show how to reproduce the
uncorrected errors, producing the attached logs.
Please reply-all as I'm not subscribed.
----------------------------------------------------
$ pacman -Q btrfs-progs
btrfs-progs 4.10.2-1
$ uname -r
4.9.24-1-MANJARO
# fallocate -l 500M good-disk
# fallocate -l 500M bad-disk
# losetup -f bad-disk # loop0
# losetup -f good-disk # loop1
# mdadm --create -v /dev/md0 --level=linear --force --raid-devices=1
/dev/loop0
mdadm: Defaulting to version 1.2 metadata
mdadm: array /dev/md0 started.
# mkfs.btrfs -m raid1 -d raid1 /dev/loop1 /dev/md0
btrfs-progs v4.10.2
See http://btrfs.wiki.kernel.org for more information.
Performing full device TRIM /dev/loop1 (500.00MiB) ...
Performing full device TRIM /dev/md0 (499.73MiB) ...
Label: (null)
UUID: d748537b-3fa4-47cc-9934-62cf391fb638
Node size: 16384
Sector size: 4096
Filesystem size: 999.73MiB
Block group profiles:
Data: RAID1 64.00MiB
Metadata: RAID1 49.94MiB
System: RAID1 8.00MiB
SSD detected: no
Incompat features: extref, skinny-metadata
Number of devices: 2
Devices:
ID SIZE PATH
1 500.00MiB /dev/loop1
2 499.73MiB /dev/md0
# mount /dev/md0 /mnt/tmp
# dd if=/dev/urandom of=/mnt/tmp/rand bs=1M
dd: error writing '/mnt/tmp/rand': No space left on device
441+0 records in
440+0 records out
461963264 bytes (462 MB, 441 MiB) copied, 5.74358 s, 80.4 MB/s
# umount /mnt/tmp
# mdadm --stop /dev/md0
mdadm: stopped /dev/md0
# mdadm --build /dev/md0 --level=faulty --raid-devices=1 /dev/loop0
mdadm: array /dev/md0 built and started.
├─vg_svelte-swap swap suspend
0792d327-566d-4306-93f4-810e247827e4 [SWAP]
└─vg_svelte-rootfs btrfs root
a1d2a0b4-8d4b-4c1c-9c87-5a55de61918e /mnt/btrfs-vol/rootfs
# lsblk -f | head -n4
NAME FSTYPE LABEL UUID
MOUNTPOINT
loop0 linux_raid_member svelte:0
f7019aa8-3b2d-4e4c-9106-635d0dddca78
└─md0 linux_raid_member svelte:0
f7019aa8-3b2d-4e4c-9106-635d0dddca78
└─md127 btrfs
d748537b-3fa4-47cc-9934-62cf391fb638
# mount /dev/md127 /mnt/tmp
# btrfs scrub start -Bd /mnt/tmp
scrub device /dev/loop1 (id 1) done
scrub started at Tue May 16 13:04:50 2017 and finished after
00:00:03
total bytes scrubbed: 441.22MiB with 0 errors
scrub device /dev/md127 (id 2) done
scrub started at Tue May 16 13:04:50 2017 and finished after
00:00:02
total bytes scrubbed: 441.22MiB with 0 errors
# # Introduce errors in /dev/md127:
# mdadm --grow /dev/md0 --layout=rp400
layout for /dev/md0 set to 12803
# btrfs scrub start -Bd /mnt/tmp
scrub device /dev/loop1 (id 1) done
scrub started at Tue May 16 13:07:57 2017 and finished after
00:00:02
total bytes scrubbed: 441.22MiB with 0 errors
scrub device /dev/md127 (id 2) done
scrub started at Tue May 16 13:07:57 2017 and finished after
00:00:03
total bytes scrubbed: 441.22MiB with 19 errors
error details: read=19
corrected errors: 19, uncorrectable errors: 0, unverified
errors: 589
WARNING: errors detected during scrubbing, corrected
# # Stop producing additional errors, keeping the already existing
badblocks:
# mdadm --grow /dev/md0 --layout=clear
layout for /dev/md0 set to 31
# # Run scrub for 2nd time:
# btrfs scrub start -Bd /mnt/tmp
scrub device /dev/loop1 (id 1) done
scrub started at Tue May 16 13:10:19 2017 and finished after
00:00:03
total bytes scrubbed: 441.22MiB with 0 errors
scrub device /dev/md127 (id 2) done
scrub started at Tue May 16 13:10:19 2017 and finished after
00:00:03
total bytes scrubbed: 441.22MiB with 19 errors
error details: read=19
corrected errors: 19, uncorrectable errors: 0, unverified
errors: 589
WARNING: errors detected during scrubbing, corrected
# # Clean up
# umount /mnt/tmp
# mdadm --stop /dev/md127
mdadm: stopped /dev/md127
# mdadm --stop /dev/md0
mdadm: stopped /dev/md0
# losetup -d /dev/loop[01]
#
--
Tom Hale
[-- Attachment #2: btrfs-fixed --]
[-- Type: text/plain, Size: 2260 bytes --]
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 132972544 on dev /dev/md127
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 107016192 on dev /dev/md127
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 340852736 on dev /dev/md127
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 366804992 on dev /dev/md127
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 392626176 on dev /dev/md127
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 314896384 on dev /dev/md127
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 418050048 on dev /dev/md127
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 434962432 on dev /dev/md127
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 486998016 on dev /dev/md127
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 512688128 on dev /dev/md127
May 16 13:10:20 svelte kernel: BTRFS error (device md127): fixed up error at logical 132972544 on dev /dev/md127
May 16 13:10:20 svelte kernel: BTRFS error (device md127): fixed up error at logical 107016192 on dev /dev/md127
May 16 13:10:21 svelte kernel: BTRFS error (device md127): fixed up error at logical 340852736 on dev /dev/md127
May 16 13:10:21 svelte kernel: BTRFS error (device md127): fixed up error at logical 366804992 on dev /dev/md127
May 16 13:10:21 svelte kernel: BTRFS error (device md127): fixed up error at logical 392626176 on dev /dev/md127
May 16 13:10:21 svelte kernel: BTRFS error (device md127): fixed up error at logical 314896384 on dev /dev/md127
May 16 13:10:21 svelte kernel: BTRFS error (device md127): fixed up error at logical 418050048 on dev /dev/md127
May 16 13:10:21 svelte kernel: BTRFS error (device md127): fixed up error at logical 434962432 on dev /dev/md127
May 16 13:10:22 svelte kernel: BTRFS error (device md127): fixed up error at logical 486998016 on dev /dev/md127
May 16 13:10:22 svelte kernel: BTRFS error (device md127): fixed up error at logical 512688128 on dev /dev/md127
[-- Attachment #3: btrfs-log --]
[-- Type: text/plain, Size: 8841 bytes --]
May 16 13:04:30 svelte kernel: BTRFS info (device md127): disk space caching is enabled
May 16 13:04:30 svelte kernel: BTRFS info (device md127): has skinny extents
May 16 13:07:57 svelte kernel: BTRFS warning (device md127): i/o error at logical 132972544 on dev /dev/md127, sector 220800, root 5, inode 261, offset 305774592, length 4096, links 1 (path: rand)
May 16 13:07:58 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 1, flush 0, corrupt 0, gen 0
May 16 13:07:58 svelte kernel: BTRFS warning (device md127): i/o error at logical 107016192 on dev /dev/md127, sector 170104, root 5, inode 261, offset 278917120, length 4096, links 1 (path: rand)
May 16 13:07:59 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 2, flush 0, corrupt 0, gen 0
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 132972544 on dev /dev/md127
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 107016192 on dev /dev/md127
May 16 13:07:59 svelte kernel: BTRFS warning (device md127): i/o error at logical 340852736 on dev /dev/md127, sector 313984, root 5, inode 261, offset 196018176, length 4096, links 1 (path: rand)
May 16 13:07:59 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 3, flush 0, corrupt 0, gen 0
May 16 13:07:59 svelte kernel: BTRFS warning (device md127): i/o error at logical 366804992 on dev /dev/md127, sector 364672, root 5, inode 261, offset 221970432, length 4096, links 1 (path: rand)
May 16 13:07:59 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 4, flush 0, corrupt 0, gen 0
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 340852736 on dev /dev/md127
May 16 13:07:59 svelte kernel: BTRFS warning (device md127): i/o error at logical 392626176 on dev /dev/md127, sector 415104, root 5, inode 261, offset 247791616, length 4096, links 1 (path: rand)
May 16 13:07:59 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 5, flush 0, corrupt 0, gen 0
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 366804992 on dev /dev/md127
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 392626176 on dev /dev/md127
May 16 13:07:59 svelte kernel: BTRFS warning (device md127): i/o error at logical 314896384 on dev /dev/md127, sector 263288, root 5, inode 261, offset 170061824, length 4096, links 1 (path: rand)
May 16 13:07:59 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 6, flush 0, corrupt 0, gen 0
May 16 13:07:59 svelte kernel: BTRFS warning (device md127): i/o error at logical 418050048 on dev /dev/md127, sector 464760, root 5, inode 261, offset 432599040, length 4096, links 1 (path: rand)
May 16 13:07:59 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 7, flush 0, corrupt 0, gen 0
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 314896384 on dev /dev/md127
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 418050048 on dev /dev/md127
May 16 13:07:59 svelte kernel: BTRFS warning (device md127): i/o error at logical 434962432 on dev /dev/md127, sector 497792, root 5, inode 261, offset 317849600, length 4096, links 1 (path: rand)
May 16 13:07:59 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 8, flush 0, corrupt 0, gen 0
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 434962432 on dev /dev/md127
May 16 13:07:59 svelte kernel: BTRFS warning (device md127): i/o error at logical 486998016 on dev /dev/md127, sector 599424, root 5, inode 261, offset 369885184, length 4096, links 1 (path: rand)
May 16 13:07:59 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 9, flush 0, corrupt 0, gen 0
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 486998016 on dev /dev/md127
May 16 13:07:59 svelte kernel: BTRFS warning (device md127): i/o error at logical 512688128 on dev /dev/md127, sector 649600, root 5, inode 261, offset 395575296, length 4096, links 1 (path: rand)
May 16 13:07:59 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 10, flush 0, corrupt 0, gen 0
May 16 13:07:59 svelte kernel: BTRFS error (device md127): fixed up error at logical 512688128 on dev /dev/md127
May 16 13:10:20 svelte kernel: BTRFS warning (device md127): i/o error at logical 132972544 on dev /dev/md127, sector 220800, root 5, inode 261, offset 305774592, length 4096, links 1 (path: rand)
May 16 13:10:20 svelte kernel: btrfs_dev_stat_print_on_error: 9 callbacks suppressed
May 16 13:10:20 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 20, flush 0, corrupt 0, gen 0
May 16 13:10:20 svelte kernel: BTRFS warning (device md127): i/o error at logical 107016192 on dev /dev/md127, sector 170104, root 5, inode 261, offset 278917120, length 4096, links 1 (path: rand)
May 16 13:10:20 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 21, flush 0, corrupt 0, gen 0
May 16 13:10:20 svelte kernel: BTRFS error (device md127): fixed up error at logical 132972544 on dev /dev/md127
May 16 13:10:20 svelte kernel: BTRFS error (device md127): fixed up error at logical 107016192 on dev /dev/md127
May 16 13:10:20 svelte kernel: BTRFS warning (device md127): i/o error at logical 340852736 on dev /dev/md127, sector 313984, root 5, inode 261, offset 196018176, length 4096, links 1 (path: rand)
May 16 13:10:21 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 22, flush 0, corrupt 0, gen 0
May 16 13:10:21 svelte kernel: BTRFS error (device md127): fixed up error at logical 340852736 on dev /dev/md127
May 16 13:10:21 svelte kernel: BTRFS warning (device md127): i/o error at logical 366804992 on dev /dev/md127, sector 364672, root 5, inode 261, offset 221970432, length 4096, links 1 (path: rand)
May 16 13:10:21 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 23, flush 0, corrupt 0, gen 0
May 16 13:10:21 svelte kernel: BTRFS error (device md127): fixed up error at logical 366804992 on dev /dev/md127
May 16 13:10:21 svelte kernel: BTRFS warning (device md127): i/o error at logical 392626176 on dev /dev/md127, sector 415104, root 5, inode 261, offset 247791616, length 4096, links 1 (path: rand)
May 16 13:10:21 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 24, flush 0, corrupt 0, gen 0
May 16 13:10:21 svelte kernel: BTRFS error (device md127): fixed up error at logical 392626176 on dev /dev/md127
May 16 13:10:21 svelte kernel: BTRFS warning (device md127): i/o error at logical 314896384 on dev /dev/md127, sector 263288, root 5, inode 261, offset 170061824, length 4096, links 1 (path: rand)
May 16 13:10:21 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 25, flush 0, corrupt 0, gen 0
May 16 13:10:21 svelte kernel: BTRFS warning (device md127): i/o error at logical 418050048 on dev /dev/md127, sector 464760, root 5, inode 261, offset 432599040, length 4096, links 1 (path: rand)
May 16 13:10:21 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 26, flush 0, corrupt 0, gen 0
May 16 13:10:21 svelte kernel: BTRFS error (device md127): fixed up error at logical 314896384 on dev /dev/md127
May 16 13:10:21 svelte kernel: BTRFS error (device md127): fixed up error at logical 418050048 on dev /dev/md127
May 16 13:10:21 svelte kernel: BTRFS warning (device md127): i/o error at logical 434962432 on dev /dev/md127, sector 497792, root 5, inode 261, offset 317849600, length 4096, links 1 (path: rand)
May 16 13:10:21 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 27, flush 0, corrupt 0, gen 0
May 16 13:10:21 svelte kernel: BTRFS error (device md127): fixed up error at logical 434962432 on dev /dev/md127
May 16 13:10:22 svelte kernel: BTRFS warning (device md127): i/o error at logical 486998016 on dev /dev/md127, sector 599424, root 5, inode 261, offset 369885184, length 4096, links 1 (path: rand)
May 16 13:10:22 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 28, flush 0, corrupt 0, gen 0
May 16 13:10:22 svelte kernel: BTRFS warning (device md127): i/o error at logical 512688128 on dev /dev/md127, sector 649600, root 5, inode 261, offset 395575296, length 4096, links 1 (path: rand)
May 16 13:10:22 svelte kernel: BTRFS error (device md127): bdev /dev/md127 errs: wr 0, rd 29, flush 0, corrupt 0, gen 0
May 16 13:10:22 svelte kernel: BTRFS error (device md127): fixed up error at logical 486998016 on dev /dev/md127
May 16 13:10:22 svelte kernel: BTRFS error (device md127): fixed up error at logical 512688128 on dev /dev/md127
[-- Attachment #4: script --]
[-- Type: text/plain, Size: 4264 bytes --]
# fallocate -l 500M good-disk
# fallocate -l 500M bad-disk
# losetup -f bad-disk # loop0
# losetup -f good-disk # loop1
# mdadm --create -v /dev/md0 --level=linear --force --raid-devices=1 /dev/loop0
mdadm: Defaulting to version 1.2 metadata
mdadm: array /dev/md0 started.
# mkfs.btrfs -m raid1 -d raid1 /dev/loop1 /dev/md0
btrfs-progs v4.10.2
See http://btrfs.wiki.kernel.org for more information.
Performing full device TRIM /dev/loop1 (500.00MiB) ...
Performing full device TRIM /dev/md0 (499.73MiB) ...
Label: (null)
UUID: d748537b-3fa4-47cc-9934-62cf391fb638
Node size: 16384
Sector size: 4096
Filesystem size: 999.73MiB
Block group profiles:
Data: RAID1 64.00MiB
Metadata: RAID1 49.94MiB
System: RAID1 8.00MiB
SSD detected: no
Incompat features: extref, skinny-metadata
Number of devices: 2
Devices:
ID SIZE PATH
1 500.00MiB /dev/loop1
2 499.73MiB /dev/md0
# mount /dev/md0 /mnt/tmp
# dd if=/dev/urandom of=/mnt/tmp/rand bs=1M
dd: error writing '/mnt/tmp/rand': No space left on device
441+0 records in
440+0 records out
461963264 bytes (462 MB, 441 MiB) copied, 5.74358 s, 80.4 MB/s
# umount /mnt/tmp
# mdadm --stop /dev/md0
mdadm: stopped /dev/md0
# mdadm --build /dev/md0 --level=faulty --raid-devices=1 /dev/loop0
mdadm: array /dev/md0 built and started.
├─vg_svelte-swap swap suspend 0792d327-566d-4306-93f4-810e247827e4 [SWAP]
└─vg_svelte-rootfs btrfs root a1d2a0b4-8d4b-4c1c-9c87-5a55de61918e /mnt/btrfs-vol/rootfs
# lsblk -f | head -n4
NAME FSTYPE LABEL UUID MOUNTPOINT
loop0 linux_raid_member svelte:0 f7019aa8-3b2d-4e4c-9106-635d0dddca78
└─md0 linux_raid_member svelte:0 f7019aa8-3b2d-4e4c-9106-635d0dddca78
└─md127 btrfs d748537b-3fa4-47cc-9934-62cf391fb638
# mount /dev/md127 /mnt/tmp
# btrfs scrub start -Bd /mnt/tmp
scrub device /dev/loop1 (id 1) done
scrub started at Tue May 16 13:04:50 2017 and finished after 00:00:03
total bytes scrubbed: 441.22MiB with 0 errors
scrub device /dev/md127 (id 2) done
scrub started at Tue May 16 13:04:50 2017 and finished after 00:00:02
total bytes scrubbed: 441.22MiB with 0 errors
# # Introduce errors in /dev/md127:
# mdadm --grow /dev/md0 --layout=rp400
layout for /dev/md0 set to 12803
# btrfs scrub start -Bd /mnt/tmp
scrub device /dev/loop1 (id 1) done
scrub started at Tue May 16 13:07:57 2017 and finished after 00:00:02
total bytes scrubbed: 441.22MiB with 0 errors
scrub device /dev/md127 (id 2) done
scrub started at Tue May 16 13:07:57 2017 and finished after 00:00:03
total bytes scrubbed: 441.22MiB with 19 errors
error details: read=19
corrected errors: 19, uncorrectable errors: 0, unverified errors: 589
WARNING: errors detected during scrubbing, corrected
# # Stop producing additional errors, keeping the already existing badblocks:
# mdadm --grow /dev/md0 --layout=clear
layout for /dev/md0 set to 31
# # Run scrub for 2nd time:
# btrfs scrub start -Bd /mnt/tmp
scrub device /dev/loop1 (id 1) done
scrub started at Tue May 16 13:10:19 2017 and finished after 00:00:03
total bytes scrubbed: 441.22MiB with 0 errors
scrub device /dev/md127 (id 2) done
scrub started at Tue May 16 13:10:19 2017 and finished after 00:00:03
total bytes scrubbed: 441.22MiB with 19 errors
error details: read=19
corrected errors: 19, uncorrectable errors: 0, unverified errors: 589
WARNING: errors detected during scrubbing, corrected
# # Clean up
# umount /mnt/tmp
# mdadm --stop /dev/md127
mdadm: stopped /dev/md127
# mdadm --stop /dev/md0
mdadm: stopped /dev/md0
# losetup -d /dev/loop[01]
# rm good-disk bad-disk
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: "Corrected" errors persist after scrubbing
2017-05-16 9:53 ` Tom Hale
@ 2017-05-16 11:27 ` Austin S. Hemmelgarn
2017-05-16 18:55 ` Chris Murphy
1 sibling, 0 replies; 6+ messages in thread
From: Austin S. Hemmelgarn @ 2017-05-16 11:27 UTC (permalink / raw)
To: Tom Hale, Chris Murphy; +Cc: Btrfs BTRFS
On 2017-05-16 05:53, Tom Hale wrote:
> Hi Chris,
>
> On 09/05/17 02:26, Chris Murphy wrote:
>> Read errors are fixed by overwrites. If the underlying device doesn't
>> report an error for the write command, it's assumed to succeed. Even
>> md and LVM raid's do this.
>
> I understand assuming writes succeed in general. However, for a tool
> which says (in its usage):
Outside of dm-error and/or dm-flakey, what hardware have you seen that
fails writes without reporting a write error? SSD's might do it at the
lowest level (below firmware), but the SSD firmware will notice and
should correct it itself, and it won't happen persistently unless the
device is essentially dead, but in general, short of the storage media
itself failing, it is entirely safe to assume that what you told the
device to write is what got written as long as the write commands succeeded.
>
> "verify checksums of data and metadata"
>
> I would expect that the tool reports the *final state* of the data:
Which is easy enough to do by hand without needing to make scrub do more
work all the time (just run a read-only scrub after the first one).
>
> * Because the explicit function of scrub is to verify that all data can
> be read.
Not exactly, it's function is to verify that checksums are correct,
verifying that there are no low-level read errors is simply a side
effect of that.
>
> * In a RAID1 situation, the sysadmin could think that the there are two
> valid copies of all data, when in fact there may only be one.
>
>> What are the complete kernel messages for the scrub event? This should
>> show what problem Btrfs detects and how it fixes it, and what sectors
>> it's fixing each time.
>
> Attached are the kernel logs (and the `grep fixed` version) showing the
> same logical blocks are "fixed" twice.
>
> Below (and attached because of formatting) I show how to reproduce the
> uncorrected errors, producing the attached logs.
>
> Please reply-all as I'm not subscribed.
>
> ----------------------------------------------------
>
> $ pacman -Q btrfs-progs
> btrfs-progs 4.10.2-1
> $ uname -r
> 4.9.24-1-MANJARO
>
> # fallocate -l 500M good-disk
> # fallocate -l 500M bad-disk
> # losetup -f bad-disk # loop0
> # losetup -f good-disk # loop1
> # mdadm --create -v /dev/md0 --level=linear --force --raid-devices=1
> /dev/loop0
> mdadm: Defaulting to version 1.2 metadata
> mdadm: array /dev/md0 started.
> # mkfs.btrfs -m raid1 -d raid1 /dev/loop1 /dev/md0
> btrfs-progs v4.10.2
> See http://btrfs.wiki.kernel.org for more information.
>
> Performing full device TRIM /dev/loop1 (500.00MiB) ...
> Performing full device TRIM /dev/md0 (499.73MiB) ...
> Label: (null)
> UUID: d748537b-3fa4-47cc-9934-62cf391fb638
> Node size: 16384
> Sector size: 4096
> Filesystem size: 999.73MiB
> Block group profiles:
> Data: RAID1 64.00MiB
> Metadata: RAID1 49.94MiB
> System: RAID1 8.00MiB
> SSD detected: no
> Incompat features: extref, skinny-metadata
> Number of devices: 2
> Devices:
> ID SIZE PATH
> 1 500.00MiB /dev/loop1
> 2 499.73MiB /dev/md0
> # mount /dev/md0 /mnt/tmp
> # dd if=/dev/urandom of=/mnt/tmp/rand bs=1M
> dd: error writing '/mnt/tmp/rand': No space left on device
> 441+0 records in
> 440+0 records out
> 461963264 bytes (462 MB, 441 MiB) copied, 5.74358 s, 80.4 MB/s
> # umount /mnt/tmp
> # mdadm --stop /dev/md0
> mdadm: stopped /dev/md0
> # mdadm --build /dev/md0 --level=faulty --raid-devices=1 /dev/loop0
> mdadm: array /dev/md0 built and started.
> ├─vg_svelte-swap swap suspend
> 0792d327-566d-4306-93f4-810e247827e4 [SWAP]
> └─vg_svelte-rootfs btrfs root
> a1d2a0b4-8d4b-4c1c-9c87-5a55de61918e /mnt/btrfs-vol/rootfs
> # lsblk -f | head -n4
> NAME FSTYPE LABEL UUID
> MOUNTPOINT
> loop0 linux_raid_member svelte:0
> f7019aa8-3b2d-4e4c-9106-635d0dddca78
> └─md0 linux_raid_member svelte:0
> f7019aa8-3b2d-4e4c-9106-635d0dddca78
> └─md127 btrfs
> d748537b-3fa4-47cc-9934-62cf391fb638
> # mount /dev/md127 /mnt/tmp
> # btrfs scrub start -Bd /mnt/tmp
> scrub device /dev/loop1 (id 1) done
> scrub started at Tue May 16 13:04:50 2017 and finished after
> 00:00:03
> total bytes scrubbed: 441.22MiB with 0 errors
> scrub device /dev/md127 (id 2) done
> scrub started at Tue May 16 13:04:50 2017 and finished after
> 00:00:02
> total bytes scrubbed: 441.22MiB with 0 errors
> # # Introduce errors in /dev/md127:
> # mdadm --grow /dev/md0 --layout=rp400
> layout for /dev/md0 set to 12803
> # btrfs scrub start -Bd /mnt/tmp
>
>
> scrub device /dev/loop1 (id 1) done
> scrub started at Tue May 16 13:07:57 2017 and finished after
> 00:00:02
> total bytes scrubbed: 441.22MiB with 0 errors
> scrub device /dev/md127 (id 2) done
> scrub started at Tue May 16 13:07:57 2017 and finished after
> 00:00:03
> total bytes scrubbed: 441.22MiB with 19 errors
> error details: read=19
> corrected errors: 19, uncorrectable errors: 0, unverified
> errors: 589
> WARNING: errors detected during scrubbing, corrected
> # # Stop producing additional errors, keeping the already existing
> badblocks:
> # mdadm --grow /dev/md0 --layout=clear
> layout for /dev/md0 set to 31
> # # Run scrub for 2nd time:
> # btrfs scrub start -Bd /mnt/tmp
>
>
> scrub device /dev/loop1 (id 1) done
> scrub started at Tue May 16 13:10:19 2017 and finished after
> 00:00:03
> total bytes scrubbed: 441.22MiB with 0 errors
> scrub device /dev/md127 (id 2) done
> scrub started at Tue May 16 13:10:19 2017 and finished after
> 00:00:03
> total bytes scrubbed: 441.22MiB with 19 errors
> error details: read=19
> corrected errors: 19, uncorrectable errors: 0, unverified
> errors: 589
> WARNING: errors detected during scrubbing, corrected
> # # Clean up
> # umount /mnt/tmp
> # mdadm --stop /dev/md127
> mdadm: stopped /dev/md127
> # mdadm --stop /dev/md0
> mdadm: stopped /dev/md0
> # losetup -d /dev/loop[01]
> #
>
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: "Corrected" errors persist after scrubbing
2017-05-16 9:53 ` Tom Hale
2017-05-16 11:27 ` Austin S. Hemmelgarn
@ 2017-05-16 18:55 ` Chris Murphy
1 sibling, 0 replies; 6+ messages in thread
From: Chris Murphy @ 2017-05-16 18:55 UTC (permalink / raw)
To: Tom Hale; +Cc: Chris Murphy, Btrfs BTRFS
On Tue, May 16, 2017 at 3:53 AM, Tom Hale <tom@hale.ee> wrote:
> # mdadm --build /dev/md0 --level=faulty --raid-devices=1 /dev/loop0
> # mdadm --grow /dev/md0 --layout=rp400
> layout for /dev/md0 set to 12803
I'm not familiar with this method of simulating problems. Everything
I've seen on this list is it's done with dm-flakey, or with the btrfs
corrupt tool. Everytime I've done that, fixups are honored and are
actually fixed. I have no idea if the above method is accepting
repairs properly. We can see from your log that Btrfs detects problems
and applies fixups. Everytime I've done this on real devices, it's
always fixed the problem. So my guess is the problem is fixed but then
the layout changes with this command
> # mdadm --grow /dev/md0 --layout=clear
> layout for /dev/md0 set to 31
And now the fixes are invalid so you get new errors again. That's just
a guess, like I said I've never seen this method of introducing faults
before so I don't know how it's behaving or what the expectations are.
The very fact Btrfs says it's sent fixups, to the specific faulty
device and sector value, and yet a 2nd scrub shows the exact same
logical errors can't be coincidence. So I suspect the methodology has
a flawed assumption, and either the fixup is not passing through
correctly or is corrupted on the way; or it's fixed but then clearing
the layout recorrupts just those fixed blocks.
>From this description:
http://linux-raid.vger.kernel.narkive.com/XFofrUH1/error-injection
>mdadm -G /dev/md0 --layout=clear
>will stop producing new errors
>mdadm -G /dev/md0 --layout=flush
>will forget all persistent errors.
I don't really understand the distinction, but it sounds like clear
might not be sufficient, that even thought fixes were applied, those
same sectors will still produce errors until flush is used.
Anyway I suspect flawed testing method.
--
Chris Murphy
^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2017-05-16 18:55 UTC | newest]
Thread overview: 6+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2017-05-06 10:33 "Corrected" errors persist after scrubbing Tom Hale
2017-05-08 19:26 ` Chris Murphy
2017-05-09 5:15 ` Duncan
2017-05-16 9:53 ` Tom Hale
2017-05-16 11:27 ` Austin S. Hemmelgarn
2017-05-16 18:55 ` Chris Murphy
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).