ubifs_check_node: bad CRC

ubifs_check_node: bad CRC

[Mickael Chazaux]

Hello,

I have been using UBIFS on embedded devices for several years now.
We never had a corrupted filesystem. Recently, I used it on a 
board design based on the previous ones. On this new board I 
had several filesystem corruptions like the one below. 

I checked the CRC of the corrupted UBIFS node, and it is incorrect.
However, the CRC of the UBI LEB and the ECC of the NAND page _are_
correct.

This node is on a PEB that was copied (copy_flag = 1 in the header)

I have been working on this a lot now, and I would like to hear the
advice of the experts on how to find the cause of this corruption.

A bit of background : 
	The volume "userdata" is used for logging. 
	Approx. 1 message per second is logged. 
	It is mounted with option sync.
	Its size is 10MiB, the ubi0 device itself is 491MiB.
	There are other volumes on ubi0, that are not
	corrupted (rootfs, etc.) . They are less busy.

I imaged the NAND and can reproduce the error like this : 

flash_eraseall /dev/mtd8
nandwrite -no /dev/mtd8 nand-image.img
ubiattach /dev/ubi_ctrl -m 8
mount -t ubifs ubi0:userdata /mnt/
echo "azer" > /mnt/azer

Trace : 

[  202.408718] UBI: attaching mtd8 to ubi0
[  203.672957] UBI: scanning is finished
[  203.695000] UBI: attached mtd8 (name "NAND.ubi", size 491 MiB) to ubi0
[  203.702056] UBI: PEB size: 131072 bytes (128 KiB), LEB size: 129024 bytes
[  203.709244] UBI: min./max. I/O unit sizes: 2048/2048, sub-page size 512
[  203.716264] UBI: VID header offset: 512 (aligned 512), data offset: 2048
[  203.723373] UBI: good PEBs: 3927, bad PEBs: 1, corrupted PEBs: 0
[  203.729729] UBI: user volume: 6, internal volumes: 1, max. volumes count: 128
[  203.737305] UBI: max/mean erase counter: 51/23, WL threshold: 4096, image sequence number: 751089049
[  203.746987] UBI: available PEBs: 589, total reserved PEBs: 3338, PEBs reserved for bad PEB handling: 79
[  203.757015] UBI: background thread "ubi_bgt0d" started, PID 248
[  213.080579] UBIFS: background thread "ubifs_bgt0_1" started, PID 250
[  213.106953] UBIFS: recovery needed
[  213.206555] UBIFS: recovery completed
[  213.210881] UBIFS: mounted UBI device 0, volume 1, name "userdata"
[  213.217435] UBIFS: LEB size: 129024 bytes (126 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes
[  213.227143] UBIFS: FS size: 9289728 bytes (8 MiB, 72 LEBs), journal size 1032193 bytes (0 MiB, 6 LEBs)
[  213.237007] UBIFS: reserved for root: 438776 bytes (428 KiB)
[  213.243019] UBIFS: media format: w4/r0 (latest is w4/r0), UUID 84A393F9-FCAF-4611-BE72-0C6E1D61115D, small LPT model
[  219.625362] UBIFS error (pid 241): ubifs_check_node: bad CRC: calculated 0xbfd1e3d2, read 0xc5aa5090
[  219.635114] UBIFS error (pid 241): ubifs_check_node: bad node at LEB 33:122880
[  219.642777]  magic          0x6101831
[  219.646651]  crc            0xc5aa5090
[  219.650634]  node_type      1 (data node)
[  219.654875]  group_type     0 (no node group)
[  219.659483]  sqnum          2408403
[  219.663187]  len            485
[  219.666513]  key            (1248, data, 4)
[  219.670953]  size           2950
[  219.674365]  compr_typ      1
[  219.677500]  data size      437
[  219.680884]  data:
[  219.683020]  00000000: 00 08 3a 35 34 20 6e 6f 68 6f 73 74 6c 61 6d 65 20 6c 6f 67 3a 20 53 48 44 53 4c 00 2e 00 00 03
[  219.694357]  00000020: 2d 20 4c 69 6e 6b b0 03 00 0e 34 20 54 72 79 69 6e 67 20 53 54 55 2d 43 20 6d 6f 60 65 0a 4a 61
[  219.705693]  00000040: 6e 20 20 36 20 31 33 32 35 35 20 15 54 01 04 32 20 73 74 61 72 74 7c 0a 0b 72 6f 6c 65 20 64 65
[  219.717028]  00000060: 74 65 63 74 69 6f 6e 2d 6e 01 36 20 6e 20 10 05 02 31 20 06 6d 01 38 20 14 6c 01 3e 34 04 20 13
[  219.728364]  00000080: 55 01 33 20 03 c4 02 00 36 3a 30 30 00 12 c5 02 33 2a fd 06 52 2f fc 06 20 16 55 00 34 00 06 c5
[  219.739703]  000000a0: 02 31 20 12 c4 02 2b c4 09 33 c4 02 20 13 54 01 20 04 c4 09 01 36 3a 30 33 20 12 c4 02 20 04 c4
[  219.751057]  000000c0: 09 20 16 6c 01 20 07 6d 08 35 20 12 dc 02 3b 6c 08 30 6f 0f 36 3a 30 20 13 54 01 20 07 6d 08 37
[  219.762391]  000000e0: 20 12 c0 02 2b 64 08 33 c4 02 20 13 54 01 20 07 6d 08 39 20 12 c5 02 32 3f bc 0d 20 13 54 81 20
[  219.773724]  00000100: 07 c4 09 20 13 6c 01 20 06 c5 09 31 20 13 14 0e 2b c4 09 32 6c 0f 20 14 54 01 20 06 c4 09 20 16
[  219.785059]  00000120: 6d 01 28 84 df 0d 29 20 44 4f 57 4e 5f 4e 4f 54 5f 52 45 41 44 59 2a a3 1a 36 3a 31 20 15 d8 10
[  219.796393]  00000140: 20 3a 68 01 20 02 7f 1d 36 3a 31 20 13 7d 0f 31 3e 44 0b 20 14 54 01 20 07 d4 09 20 13 c4 02 20
[  219.807727]  00000160: 07 7c 08 20 13 ec 10 2b 44 12 33 44 0b 20 13 54 01 20 06 45 12 31 20 13 7c 0f 2b 44 12 32 0d 15
[  219.819060]  00000180: 32 20 13 64 0f 20 06 44 12 20 14 6c 01 20 06 6d 08 32 20 13 10 0e 2b 44 12 33 34 04 20 13 54 01
[  219.830395]  000001a0: 2a c4 09 0b 6f 6c 65 20 64 65 74 65 63 74 69 6f 6e 0a 11 00 00
[  219.838690] CPU: 0 PID: 241 Comm: sh Not tainted 3.12.10 #1
[  219.844603] Backtrace: 
[  219.847248] [<c00120fc>] (dump_backtrace+0x0/0x108) from [<c001221c>] (show_stack+0x18/0x1c)
[  219.856195]  r6:cd596000 r5:d0b1f000 r4:ffffff8b
[  219.861136] [<c0012204>] (show_stack+0x0/0x1c) from [<c0815a34>] (dump_stack+0x20/0x2c)
[  219.869620] [<c0815a14>] (dump_stack+0x0/0x2c) from [<c0247354>] (ubifs_check_node+0x1b8/0x2d8)
[  219.878858] [<c024719c>] (ubifs_check_node+0x0/0x2d8) from [<c024f020>] (ubifs_scan_a_node+0xd8/0x1e8)
[  219.888738] [<c024ef48>] (ubifs_scan_a_node+0x0/0x1e8) from [<c024f194>] (ubifs_scan+0x64/0x300)
[  219.898067] [<c024f130>] (ubifs_scan+0x0/0x300) from [<c0253cb8>] (ubifs_garbage_collect_leb+0x84/0x7f4)
[  219.908127] [<c0253c34>] (ubifs_garbage_collect_leb+0x0/0x7f4) from [<c0254550>] (ubifs_garbage_collect+0x128/0x3b4)
[  219.919306] [<c0254428>] (ubifs_garbage_collect+0x0/0x3b4) from [<c023a240>] (make_reservation+0x120/0x440)
[  219.929643] [<c023a120>] (make_reservation+0x0/0x440) from [<c023c380>] (ubifs_jnl_update+0x12c/0x640)
[  219.939517] [<c023c254>] (ubifs_jnl_update+0x0/0x640) from [<c02413a0>] (ubifs_create+0x10c/0x1b0)
[  219.949027] [<c0241294>] (ubifs_create+0x0/0x1b0) from [<c00e5d8c>] (vfs_create+0xb0/0xdc)
[  219.957796] [<c00e5cdc>] (vfs_create+0x0/0xdc) from [<c00e6f50>] (do_last+0x94c/0xc9c)
[  219.966186]  r8:00020241 r7:cd5c7f5c r6:cd5c7ed0 r5:c9161f70 r4:000081a4
[  219.973334] [<c00e6604>] (do_last+0x0/0xc9c) from [<c00e7368>] (path_openat+0xc8/0x5ac)
[  219.981829] [<c00e72a0>] (path_openat+0x0/0x5ac) from [<c00e7960>] (do_filp_open+0x38/0x8c)
[  219.990707] [<c00e7928>] (do_filp_open+0x0/0x8c) from [<c00d7a94>] (do_sys_open+0x118/0x1d4)
[  219.999635]  r8:cd620000 r7:00000003 r6:000ad29c r5:ffffff9c r4:00020241
[  220.006786] [<c00d797c>] (do_sys_open+0x0/0x1d4) from [<c00d7b8c>] (SyS_open+0x24/0x28)
[  220.015288] [<c00d7b68>] (SyS_open+0x0/0x28) from [<c000ebc0>] (ret_fast_syscall+0x0/0x30)
[  220.024053] UBIFS error (pid 241): ubifs_scan: bad node
[  220.029585] UBIFS error (pid 241): ubifs_scanned_corruption: corruption at LEB 33:122880
[  220.038164] UBIFS error (pid 241): ubifs_scanned_corruption: first 6144 bytes from LEB 33:122880
[  220.047498] 00000000: 06101831 c5aa5090 0024bfd3 00000000 000001e5 00000001 000004e0 20000004  1....P....$.................... 
(clipped) 
[  220.051722] UBIFS error (pid 241): ubifs_scan: LEB 33 scanning failed
[  220.058571] UBIFS warning (pid 241): ubifs_ro_mode: switched to read-only mode, error -117
[  220.067357] CPU: 0 PID: 241 Comm: sh Not tainted 3.12.10 #1
[  220.073271] Backtrace: 
[  220.075883] [<c00120fc>] (dump_backtrace+0x0/0x108) from [<c001221c>] (show_stack+0x18/0x1c)
[  220.084830]  r6:cd596000 r5:ffffff8b r4:00000000
[  220.089747] [<c0012204>] (show_stack+0x0/0x1c) from [<c0815a34>] (dump_stack+0x20/0x2c)
[  220.098264] [<c0815a14>] (dump_stack+0x0/0x2c) from [<c0246c1c>] (ubifs_ro_mode+0x64/0x70)
[  220.107039] [<c0246bb8>] (ubifs_ro_mode+0x0/0x70) from [<c025464c>] (ubifs_garbage_collect+0x224/0x3b4)
[  220.117012] [<c0254428>] (ubifs_garbage_collect+0x0/0x3b4) from [<c023a240>] (make_reservation+0x120/0x440)
[  220.127348] [<c023a120>] (make_reservation+0x0/0x440) from [<c023c380>] (ubifs_jnl_update+0x12c/0x640)
[  220.137230] [<c023c254>] (ubifs_jnl_update+0x0/0x640) from [<c02413a0>] (ubifs_create+0x10c/0x1b0)
[  220.146736] [<c0241294>] (ubifs_create+0x0/0x1b0) from [<c00e5d8c>] (vfs_create+0xb0/0xdc)
[  220.155506] [<c00e5cdc>] (vfs_create+0x0/0xdc) from [<c00e6f50>] (do_last+0x94c/0xc9c)
[  220.163897]  r8:00020241 r7:cd5c7f5c r6:cd5c7ed0 r5:c9161f70 r4:000081a4
[  220.171045] [<c00e6604>] (do_last+0x0/0xc9c) from [<c00e7368>] (path_openat+0xc8/0x5ac)
[  220.179522] [<c00e72a0>] (path_openat+0x0/0x5ac) from [<c00e7960>] (do_filp_open+0x38/0x8c)
[  220.188388] [<c00e7928>] (do_filp_open+0x0/0x8c) from [<c00d7a94>] (do_sys_open+0x118/0x1d4)
[  220.197331]  r8:cd620000 r7:00000003 r6:000ad29c r5:ffffff9c r4:00020241
[  220.204483] [<c00d797c>] (do_sys_open+0x0/0x1d4) from [<c00d7b8c>] (SyS_open+0x24/0x28)
[  220.212982] [<c00d7b68>] (SyS_open+0x0/0x28) from [<c000ebc0>] (ret_fast_syscall+0x0/0x30)
[  220.222268] UBIFS error (pid 241): make_reservation: cannot reserve 384 bytes in jhead 1, error -117
[  220.232023] UBIFS error (pid 241): ubifs_create: cannot create regular file, error -117

Best regards,

-- 
Mickael Chazaux
Software Engineer
Tel : (33) 476 042 006
Fax : (33) 476 042 001

ETIC TELECOM
13, Chemin du Vieux Chêne
38240 MEYLAN
Tel: 33 4 76 04 20 00
fax : 33 4 76 04 20 01

______________________________________________________
Linux MTD discussion mailing list
http://lists.infradead.org/mailman/listinfo/linux-mtd/

Re: ubifs_check_node: bad CRC

[Richard Weinberger]

Mickael,

On Mon, Jul 29, 2019 at 3:28 PM Mickael Chazaux
<mickael.chazaux@etictelecom.com> wrote:
>
> Hello,
>
> I have been using UBIFS on embedded devices for several years now.
> We never had a corrupted filesystem. Recently, I used it on a
> board design based on the previous ones. On this new board I
> had several filesystem corruptions like the one below.
>
> I checked the CRC of the corrupted UBIFS node, and it is incorrect.
> However, the CRC of the UBI LEB and the ECC of the NAND page _are_
> correct.
>
> This node is on a PEB that was copied (copy_flag = 1 in the header)

Side note, you are only allowed to check the CRC of a LEB iff copy_flag is set
and there is a second LEB with the same volume id and LEB number present.
Then you can use the CRC of the LEB with the higher sqnum

Otherwise the CRC can be outdated.

> I have been working on this a lot now, and I would like to hear the
> advice of the experts on how to find the cause of this corruption.
>
> A bit of background :
>         The volume "userdata" is used for logging.
>         Approx. 1 message per second is logged.
>         It is mounted with option sync.
>         Its size is 10MiB, the ubi0 device itself is 491MiB.
>         There are other volumes on ubi0, that are not
>         corrupted (rootfs, etc.) . They are less busy.
>
> I imaged the NAND and can reproduce the error like this :
>
> flash_eraseall /dev/mtd8
> nandwrite -no /dev/mtd8 nand-image.img
> ubiattach /dev/ubi_ctrl -m 8
> mount -t ubifs ubi0:userdata /mnt/
> echo "azer" > /mnt/azer

That easy?
Hmm, sounds a bit like a bug in your NAND driver. Did you test it?

Please also disable compression in UBIFS, then the read back data maybe gives
you a hint what went wrong.

Thanks,
//richard

______________________________________________________
Linux MTD discussion mailing list
http://lists.infradead.org/mailman/listinfo/linux-mtd/

Re: ubifs_check_node: bad CRC

[Mickael Chazaux]

Hi Richard, 

>>
>> I imaged the NAND and can reproduce the error like this :
>>
>> flash_eraseall /dev/mtd8
>> nandwrite -no /dev/mtd8 nand-image.img
>> ubiattach /dev/ubi_ctrl -m 8
>> mount -t ubifs ubi0:userdata /mnt/
>> echo "azer" > /mnt/azer
> 
> That easy?
> Hmm, sounds a bit like a bug in your NAND driver. Did you test it?
> 

Sorry, I meant : the "nand-image.img" file is coming from a corrupted device.
I ran the mtd_* kernel module tests yesterday. All seems good, but the torture test
is not yet finished (see below).

The problem occured in the field on several devices, and I cannot reproduce it 
in the lab.

> Please also disable compression in UBIFS, then the read back data maybe gives
> you a hint what went wrong.

In the corrupted node I see data from syslog. This system is a bit different 
than the others we usually make, as there are more power cuts and more log writes.

Thank you,

Mickael


[ 5413.404322] =================================================
[ 5413.410491] mtd_oobtest: MTD device: 8
[ 5413.414474] mtd_oobtest: MTD device size 514850816, eraseblock size 131072, page size 2048, count of eraseblocks 3928, pages per eraseblock 64, OOB size 64
[ 5413.429413] mtd_test: scanning for bad eraseblocks
[ 5413.575972] mtd_test: block 1340 is bad
[ 5413.851910] mtd_test: scanned 3928 eraseblocks, 1 are bad
[ 5413.857626] mtd_oobtest: test 1 of 5
[ 5418.697456] mtd_oobtest: writing OOBs of whole device
[ 5418.720169] mtd_oobtest: written up to eraseblock 0
[ 5423.162434] mtd_oobtest: written up to eraseblock 256
[ 5427.602317] mtd_oobtest: written up to eraseblock 512
[ 5432.040495] mtd_oobtest: written up to eraseblock 768
[ 5436.482085] mtd_oobtest: written up to eraseblock 1024
[ 5440.921463] mtd_oobtest: written up to eraseblock 1280
[ 5445.342351] mtd_oobtest: written up to eraseblock 1536
[ 5449.780333] mtd_oobtest: written up to eraseblock 1792
[ 5454.219675] mtd_oobtest: written up to eraseblock 2048
[ 5458.665451] mtd_oobtest: written up to eraseblock 2304
[ 5463.104220] mtd_oobtest: written up to eraseblock 2560
[ 5467.545202] mtd_oobtest: written up to eraseblock 2816
[ 5471.986045] mtd_oobtest: written up to eraseblock 3072
[ 5476.426066] mtd_oobtest: written up to eraseblock 3328
[ 5480.867515] mtd_oobtest: written up to eraseblock 3584
[ 5485.309581] mtd_oobtest: written up to eraseblock 3840
[ 5486.823072] mtd_oobtest: written 3928 eraseblocks
[ 5486.828061] mtd_oobtest: verifying all eraseblocks
[ 5486.837360] mtd_oobtest: verified up to eraseblock 0
[ 5487.918137] mtd_oobtest: verified up to eraseblock 256
[ 5488.998900] mtd_oobtest: verified up to eraseblock 512
[ 5490.080089] mtd_oobtest: verified up to eraseblock 768
[ 5491.161260] mtd_oobtest: verified up to eraseblock 1024
[ 5492.241854] mtd_oobtest: verified up to eraseblock 1280
[ 5493.318356] mtd_oobtest: verified up to eraseblock 1536
[ 5494.398855] mtd_oobtest: verified up to eraseblock 1792
[ 5495.479755] mtd_oobtest: verified up to eraseblock 2048
[ 5496.560331] mtd_oobtest: verified up to eraseblock 2304
[ 5497.641029] mtd_oobtest: verified up to eraseblock 2560
[ 5498.721400] mtd_oobtest: verified up to eraseblock 2816
[ 5499.802138] mtd_oobtest: verified up to eraseblock 3072
[ 5500.882520] mtd_oobtest: verified up to eraseblock 3328
[ 5501.963106] mtd_oobtest: verified up to eraseblock 3584
[ 5503.043905] mtd_oobtest: verified up to eraseblock 3840
[ 5503.414587] mtd_oobtest: verified 3928 eraseblocks
[ 5503.419657] mtd_oobtest: test 2 of 5
[ 5508.257289] mtd_oobtest: writing OOBs of whole device
[ 5508.279972] mtd_oobtest: written up to eraseblock 0
[ 5512.716652] mtd_oobtest: written up to eraseblock 256
[ 5517.153175] mtd_oobtest: written up to eraseblock 512
[ 5521.588800] mtd_oobtest: written up to eraseblock 768
[ 5526.025484] mtd_oobtest: written up to eraseblock 1024
[ 5530.463071] mtd_oobtest: written up to eraseblock 1280
[ 5534.883615] mtd_oobtest: written up to eraseblock 1536
[ 5539.319681] mtd_oobtest: written up to eraseblock 1792
[ 5543.756419] mtd_oobtest: written up to eraseblock 2048
[ 5548.193159] mtd_oobtest: written up to eraseblock 2304
[ 5552.629020] mtd_oobtest: written up to eraseblock 2560
[ 5557.065773] mtd_oobtest: written up to eraseblock 2816
[ 5561.502801] mtd_oobtest: written up to eraseblock 3072
[ 5565.940317] mtd_oobtest: written up to eraseblock 3328
[ 5570.379654] mtd_oobtest: written up to eraseblock 3584
[ 5574.818812] mtd_oobtest: written up to eraseblock 3840
[ 5576.331667] mtd_oobtest: written 3928 eraseblocks
[ 5576.336649] mtd_oobtest: verifying all eraseblocks
[ 5576.345902] mtd_oobtest: verified up to eraseblock 0
[ 5577.409516] mtd_oobtest: verified up to eraseblock 256
[ 5578.472968] mtd_oobtest: verified up to eraseblock 512
[ 5579.536875] mtd_oobtest: verified up to eraseblock 768
[ 5580.600794] mtd_oobtest: verified up to eraseblock 1024
[ 5581.665090] mtd_oobtest: verified up to eraseblock 1280
[ 5582.724904] mtd_oobtest: verified up to eraseblock 1536
[ 5583.789025] mtd_oobtest: verified up to eraseblock 1792
[ 5584.853233] mtd_oobtest: verified up to eraseblock 2048
[ 5585.917338] mtd_oobtest: verified up to eraseblock 2304
[ 5586.981018] mtd_oobtest: verified up to eraseblock 2560
[ 5588.045023] mtd_oobtest: verified up to eraseblock 2816
[ 5589.108721] mtd_oobtest: verified up to eraseblock 3072
[ 5590.172486] mtd_oobtest: verified up to eraseblock 3328
[ 5591.236304] mtd_oobtest: verified up to eraseblock 3584
[ 5592.299835] mtd_oobtest: verified up to eraseblock 3840
[ 5592.664836] mtd_oobtest: verified 3928 eraseblocks
[ 5592.669904] mtd_oobtest: test 3 of 5
[ 5597.507429] mtd_oobtest: writing OOBs of whole device
[ 5597.530046] mtd_oobtest: written up to eraseblock 0
[ 5601.892389] mtd_oobtest: written up to eraseblock 256
[ 5606.253684] mtd_oobtest: written up to eraseblock 512
[ 5610.616762] mtd_oobtest: written up to eraseblock 768
[ 5614.982534] mtd_oobtest: written up to eraseblock 1024
[ 5619.347226] mtd_oobtest: written up to eraseblock 1280
[ 5623.695084] mtd_oobtest: written up to eraseblock 1536
[ 5628.056769] mtd_oobtest: written up to eraseblock 1792
[ 5632.415995] mtd_oobtest: written up to eraseblock 2048
[ 5636.778889] mtd_oobtest: written up to eraseblock 2304
[ 5641.142626] mtd_oobtest: written up to eraseblock 2560
[ 5645.507464] mtd_oobtest: written up to eraseblock 2816
[ 5649.878307] mtd_oobtest: written up to eraseblock 3072
[ 5654.246151] mtd_oobtest: written up to eraseblock 3328
[ 5658.618988] mtd_oobtest: written up to eraseblock 3584
[ 5662.997712] mtd_oobtest: written up to eraseblock 3840
[ 5664.487326] mtd_oobtest: written 3928 eraseblocks
[ 5664.492328] mtd_oobtest: verifying all eraseblocks
[ 5664.505684] mtd_oobtest: verified up to eraseblock 0
[ 5666.637997] mtd_oobtest: verified up to eraseblock 256
[ 5668.770111] mtd_oobtest: verified up to eraseblock 512
[ 5670.902296] mtd_oobtest: verified up to eraseblock 768
[ 5673.034654] mtd_oobtest: verified up to eraseblock 1024
[ 5675.167603] mtd_oobtest: verified up to eraseblock 1280
[ 5677.292282] mtd_oobtest: verified up to eraseblock 1536
[ 5679.424938] mtd_oobtest: verified up to eraseblock 1792
[ 5681.557466] mtd_oobtest: verified up to eraseblock 2048
[ 5683.689666] mtd_oobtest: verified up to eraseblock 2304
[ 5685.821972] mtd_oobtest: verified up to eraseblock 2560
[ 5687.953818] mtd_oobtest: verified up to eraseblock 2816
[ 5690.086286] mtd_oobtest: verified up to eraseblock 3072
[ 5692.218900] mtd_oobtest: verified up to eraseblock 3328
[ 5694.350754] mtd_oobtest: verified up to eraseblock 3584
[ 5696.482561] mtd_oobtest: verified up to eraseblock 3840
[ 5697.210533] mtd_oobtest: verified 3928 eraseblocks
[ 5697.215607] mtd_oobtest: test 4 of 5
[ 5702.053539] mtd_oobtest: attempting to start write past end of OOB
[ 5702.060099] mtd_oobtest: an error is expected...
[ 5702.065001] mtd_oobtest: error occurred as expected
[ 5702.070160] mtd_oobtest: attempting to start read past end of OOB
[ 5702.076618] mtd_oobtest: an error is expected...
[ 5702.081518] mtd_oobtest: error occurred as expected
[ 5702.086677] mtd_oobtest: attempting to write past end of device
[ 5702.092949] mtd_oobtest: an error is expected...
[ 5702.097831] mtd_oobtest: error occurred as expected
[ 5702.103003] mtd_oobtest: attempting to read past end of device
[ 5702.109170] mtd_oobtest: an error is expected...
[ 5702.114066] mtd_oobtest: error occurred as expected
[ 5702.120459] mtd_oobtest: attempting to write past end of device
[ 5702.126719] mtd_oobtest: an error is expected...
[ 5702.131680] mtd_oobtest: error occurred as expected
[ 5702.136843] mtd_oobtest: attempting to read past end of device
[ 5702.143075] mtd_oobtest: an error is expected...
[ 5702.147960] mtd_oobtest: error occurred as expected
[ 5702.153139] mtd_oobtest: test 5 of 5
[ 5706.990511] mtd_oobtest: writing OOBs of whole device
[ 5706.996169] mtd_oobtest: written up to eraseblock 0
[ 5707.001889] mtd_oobtest: written up to eraseblock 0
[ 5707.147066] mtd_oobtest: written up to eraseblock 256
[ 5707.152701] mtd_oobtest: written up to eraseblock 256
[ 5707.298183] mtd_oobtest: written up to eraseblock 512
[ 5707.303865] mtd_oobtest: written up to eraseblock 512
[ 5707.449384] mtd_oobtest: written up to eraseblock 768
[ 5707.455063] mtd_oobtest: written up to eraseblock 768
[ 5707.600910] mtd_oobtest: written up to eraseblock 1024
[ 5707.606662] mtd_oobtest: written up to eraseblock 1024
[ 5707.752264] mtd_oobtest: written up to eraseblock 1280
[ 5707.757970] mtd_oobtest: written up to eraseblock 1280
[ 5707.902742] mtd_oobtest: written up to eraseblock 1536
[ 5707.908449] mtd_oobtest: written up to eraseblock 1536
[ 5708.053945] mtd_oobtest: written up to eraseblock 1792
[ 5708.059701] mtd_oobtest: written up to eraseblock 1792
[ 5708.204961] mtd_oobtest: written up to eraseblock 2048
[ 5708.210732] mtd_oobtest: written up to eraseblock 2048
[ 5708.356839] mtd_oobtest: written up to eraseblock 2304
[ 5708.362612] mtd_oobtest: written up to eraseblock 2304
[ 5708.507666] mtd_oobtest: written up to eraseblock 2560
[ 5708.513390] mtd_oobtest: written up to eraseblock 2560
[ 5708.659872] mtd_oobtest: written up to eraseblock 2816
[ 5708.665596] mtd_oobtest: written up to eraseblock 2816
[ 5708.811630] mtd_oobtest: written up to eraseblock 3072
[ 5708.817337] mtd_oobtest: written up to eraseblock 3072
[ 5708.963204] mtd_oobtest: written up to eraseblock 3328
[ 5708.968912] mtd_oobtest: written up to eraseblock 3328
[ 5709.115684] mtd_oobtest: written up to eraseblock 3584
[ 5709.121412] mtd_oobtest: written up to eraseblock 3584
[ 5709.268444] mtd_oobtest: written up to eraseblock 3840
[ 5709.274170] mtd_oobtest: written up to eraseblock 3840
[ 5709.327163] mtd_oobtest: written 3927 eraseblocks
[ 5709.332154] mtd_oobtest: verifying all eraseblocks
[ 5709.337362] mtd_oobtest: verified up to eraseblock 0
[ 5709.375982] mtd_oobtest: verified up to eraseblock 256
[ 5709.414809] mtd_oobtest: verified up to eraseblock 512
[ 5709.453600] mtd_oobtest: verified up to eraseblock 768
[ 5709.492392] mtd_oobtest: verified up to eraseblock 1024
[ 5709.531275] mtd_oobtest: verified up to eraseblock 1280
[ 5709.569885] mtd_oobtest: verified up to eraseblock 1536
[ 5709.608768] mtd_oobtest: verified up to eraseblock 1792
[ 5709.647651] mtd_oobtest: verified up to eraseblock 2048
[ 5709.686563] mtd_oobtest: verified up to eraseblock 2304
[ 5709.725454] mtd_oobtest: verified up to eraseblock 2560
[ 5709.764332] mtd_oobtest: verified up to eraseblock 2816
[ 5709.803232] mtd_oobtest: verified up to eraseblock 3072
[ 5709.842266] mtd_oobtest: verified up to eraseblock 3328
[ 5709.881215] mtd_oobtest: verified up to eraseblock 3584
[ 5709.920091] mtd_oobtest: verified up to eraseblock 3840
[ 5709.936870] mtd_oobtest: verified 3927 eraseblocks
[ 5709.941956] mtd_oobtest: finished with 0 errors
[ 5709.946753] =================================================
[ 5814.956006] 
[ 5814.957619] =================================================
[ 5814.963790] mtd_stresstest: MTD device: 8
[ 5814.968050] mtd_stresstest: MTD device size 514850816, eraseblock size 131072, page size 2048, count of eraseblocks 3928, pages per eraseblock 64, OOB size 64
[ 5814.988256] mtd_test: scanning for bad eraseblocks
[ 5815.135242] mtd_test: block 1340 is bad
[ 5815.411649] mtd_test: scanned 3928 eraseblocks, 1 are bad
[ 5815.417371] mtd_stresstest: doing operations
[ 5815.421904] mtd_stresstest: 0 operations done
[ 5836.025793] mtd_stresstest: 1024 operations done
[ 5856.228779] mtd_stresstest: 2048 operations done
[ 5876.470081] mtd_stresstest: 3072 operations done
[ 5896.150716] mtd_stresstest: 4096 operations done
[ 5915.446882] mtd_stresstest: 5120 operations done
[ 5934.046827] mtd_stresstest: 6144 operations done
[ 5952.001219] mtd_stresstest: 7168 operations done
[ 5970.345806] mtd_stresstest: 8192 operations done
[ 5988.697141] mtd_stresstest: 9216 operations done
[ 6003.348364] mtd_stresstest: finished, 10000 operations done
[ 6003.354570] =================================================
[ 6076.943773] 
[ 6076.945387] ==================================================
[ 6076.951671] mtd_nandbiterrs: MTD device: 8
[ 6076.956017] mtd_nandbiterrs: MTD device size 514850816, eraseblock=131072, page=2048, oob=64
[ 6076.964968] mtd_nandbiterrs: Device uses 4 subpages of 512 bytes
[ 6076.971347] mtd_nandbiterrs: Using page=0, offset=0, eraseblock=0
[ 6076.979051] mtd_nandbiterrs: incremental biterrors test
[ 6076.984731] mtd_nandbiterrs: write_page
[ 6076.989258] mtd_nandbiterrs: rewrite page
[ 6076.993892] mtd_nandbiterrs: read_page
[ 6076.998177] mtd_nandbiterrs: verify_page
[ 6077.002516] mtd_nandbiterrs: Successfully corrected 0 bit errors per subpage
[ 6077.009974] mtd_nandbiterrs: Inserted biterror @ 0/5
[ 6077.015247] mtd_nandbiterrs: Inserted biterror @ 512/6
[ 6077.020699] mtd_nandbiterrs: Inserted biterror @ 1025/7
[ 6077.026226] mtd_nandbiterrs: Inserted biterror @ 1536/6
[ 6077.031775] mtd_nandbiterrs: rewrite page
[ 6077.036797] mtd_nandbiterrs: read_page
[ 6077.041136] mtd_nandbiterrs: Read reported 4 corrected bit errors
[ 6077.047584] mtd_nandbiterrs: verify_page
[ 6077.051888] mtd_nandbiterrs: Successfully corrected 1 bit errors per subpage
[ 6077.059345] mtd_nandbiterrs: Inserted biterror @ 0/2
[ 6077.064612] mtd_nandbiterrs: Inserted biterror @ 512/5
[ 6077.070047] mtd_nandbiterrs: Inserted biterror @ 1026/6
[ 6077.075589] mtd_nandbiterrs: Inserted biterror @ 1536/3
[ 6077.081130] mtd_nandbiterrs: rewrite page
[ 6077.085743] mtd_nandbiterrs: read_page
[ 6077.090004] __nand_correct_data: uncorrectable ECC error
[ 6077.095463] __nand_correct_data: uncorrectable ECC error__nand_correct_data: uncorrectable ECC error
[ 6077.105155] __nand_correct_data: uncorrectable ECC error<3>[ 6077.110795] mtd_nandbiterrs: error: read failed at 0x0
[ 6077.116232] mtd_nandbiterrs: After 2 biterrors per subpage, read reported error -74
[ 6077.125586] mtd_nandbiterrs: finished successfully.
[ 6077.130762] ==================================================
[ 6116.618198] mtd_nandecctest: unknown parameter 'dev' ignored
[ 6116.624730] mtd_nandecctest: ok - no-bit-error-256
[ 6116.629820] mtd_nandecctest: ok - single-bit-error-in-data-correct-256
[ 6116.636780] mtd_nandecctest: ok - single-bit-error-in-ecc-correct-256
[ 6116.643625] __nand_correct_data: uncorrectable ECC error
[ 6116.649065] mtd_nandecctest: ok - double-bit-error-in-data-detect-256
[ 6116.656094] __nand_correct_data: uncorrectable ECC error
[ 6116.661548] mtd_nandecctest: ok - single-bit-error-in-data-and-ecc-detect-256
[ 6116.669286] __nand_correct_data: uncorrectable ECC error
[ 6116.674737] mtd_nandecctest: ok - double-bit-error-in-ecc-detect-256
[ 6116.681701] mtd_nandecctest: ok - no-bit-error-512
[ 6116.686781] mtd_nandecctest: ok - single-bit-error-in-data-correct-512
[ 6116.693716] mtd_nandecctest: ok - single-bit-error-in-ecc-correct-512
[ 6116.700548] __nand_correct_data: uncorrectable ECC error
[ 6116.705983] mtd_nandecctest: ok - double-bit-error-in-data-detect-512
[ 6116.713031] __nand_correct_data: uncorrectable ECC error
[ 6116.718469] mtd_nandecctest: ok - single-bit-error-in-data-and-ecc-detect-512
[ 6116.726229] __nand_correct_data: uncorrectable ECC error
[ 6116.731685] mtd_nandecctest: ok - double-bit-error-in-ecc-detect-512
[ 6210.317171] mtd_pagetest: `' invalid for parameter `dev'
[ 6214.160109] 
[ 6214.161844] =================================================
[ 6214.167928] mtd_pagetest: MTD device: 8
[ 6214.172034] mtd_pagetest: MTD device size 514850816, eraseblock size 131072, page size 2048, count of eraseblocks 3928, pages per eraseblock 64, OOB size 64
[ 6214.186906] mtd_test: scanning for bad eraseblocks
[ 6214.333227] mtd_test: block 1340 is bad
[ 6214.609094] mtd_test: scanned 3928 eraseblocks, 1 are bad
[ 6214.614831] mtd_pagetest: erasing whole device
[ 6219.455151] mtd_pagetest: erased 3928 eraseblocks
[ 6219.460149] mtd_pagetest: writing whole device
[ 6219.495395] mtd_pagetest: written up to eraseblock 0
[ 6227.299119] mtd_pagetest: written up to eraseblock 256
[ 6235.107834] mtd_pagetest: written up to eraseblock 512
[ 6242.857609] mtd_pagetest: written up to eraseblock 768
[ 6250.614131] mtd_pagetest: written up to eraseblock 1024
[ 6258.347823] mtd_pagetest: written up to eraseblock 1280
[ 6266.053320] mtd_pagetest: written up to eraseblock 1536
[ 6273.783338] mtd_pagetest: written up to eraseblock 1792
[ 6281.511652] mtd_pagetest: written up to eraseblock 2048
[ 6289.251850] mtd_pagetest: written up to eraseblock 2304
[ 6296.998599] mtd_pagetest: written up to eraseblock 2560
[ 6304.752642] mtd_pagetest: written up to eraseblock 2816
[ 6312.514425] mtd_pagetest: written up to eraseblock 3072
[ 6320.237306] mtd_pagetest: written up to eraseblock 3328
[ 6327.978076] mtd_pagetest: written up to eraseblock 3584
[ 6335.736566] mtd_pagetest: written up to eraseblock 3840
[ 6338.378819] mtd_pagetest: written 3928 eraseblocks
[ 6338.383949] mtd_pagetest: verifying all eraseblocks
[ 6338.507400] mtd_pagetest: verified up to eraseblock 0
[ 6368.823427] mtd_pagetest: verified up to eraseblock 256
[ 6399.128609] mtd_pagetest: verified up to eraseblock 512
[ 6429.425984] mtd_pagetest: verified up to eraseblock 768
[ 6459.724052] mtd_pagetest: verified up to eraseblock 1024
[ 6490.025215] mtd_pagetest: verified up to eraseblock 1280
[ 6520.225621] mtd_pagetest: verified up to eraseblock 1536
[ 6550.535370] mtd_pagetest: verified up to eraseblock 1792
[ 6580.835068] mtd_pagetest: verified up to eraseblock 2048
[ 6611.150737] mtd_pagetest: verified up to eraseblock 2304
[ 6641.449877] mtd_pagetest: verified up to eraseblock 2560
[ 6671.757231] mtd_pagetest: verified up to eraseblock 2816
[ 6702.057533] mtd_pagetest: verified up to eraseblock 3072
[ 6732.365896] mtd_pagetest: verified up to eraseblock 3328
[ 6762.662085] mtd_pagetest: verified up to eraseblock 3584
[ 6792.961595] mtd_pagetest: verified up to eraseblock 3840
[ 6803.260899] mtd_pagetest: verified 3928 eraseblocks
[ 6803.266092] mtd_pagetest: crosstest
[ 6803.270468] mtd_pagetest: reading page at 0x0
[ 6803.275385] mtd_pagetest: reading page at 0x1eaff800
[ 6803.280962] mtd_pagetest: reading page at 0x0
[ 6803.285876] mtd_pagetest: verifying pages read at 0x0 match
[ 6803.291823] mtd_pagetest: crosstest ok
[ 6803.295789] mtd_pagetest: erasecrosstest
[ 6803.299936] mtd_pagetest: erasing block 0
[ 6803.305439] mtd_pagetest: writing 1st page of block 0
[ 6803.311289] mtd_pagetest: reading 1st page of block 0
[ 6803.316928] mtd_pagetest: verifying 1st page of block 0
[ 6803.322504] mtd_pagetest: erasing block 0
[ 6803.327977] mtd_pagetest: writing 1st page of block 0
[ 6803.333808] mtd_pagetest: erasing block 3927
[ 6803.339556] mtd_pagetest: reading 1st page of block 0
[ 6803.345220] mtd_pagetest: verifying 1st page of block 0
[ 6803.350795] mtd_pagetest: erasecrosstest ok
[ 6803.355217] mtd_pagetest: erasetest
[ 6803.358903] mtd_pagetest: erasing block 0
[ 6803.364391] mtd_pagetest: writing 1st page of block 0
[ 6803.370203] mtd_pagetest: erasing block 0
[ 6803.375694] mtd_pagetest: reading 1st page of block 0
[ 6803.381346] mtd_pagetest: verifying 1st page of block 0 is all 0xff
[ 6803.387990] mtd_pagetest: erasetest ok
[ 6803.391969] mtd_pagetest: finished with 0 errors
[ 6803.396856] =================================================
[ 6877.130696] 
[ 6877.132306] =================================================
[ 6877.138384] mtd_readtest: MTD device: 8
[ 6877.142498] mtd_readtest: MTD device size 514850816, eraseblock size 131072, page size 2048, count of eraseblocks 3928, pages per eraseblock 64, OOB size 64
[ 6877.157359] mtd_test: scanning for bad eraseblocks
[ 6877.303751] mtd_test: block 1340 is bad
[ 6877.580143] mtd_test: scanned 3928 eraseblocks, 1 are bad
[ 6877.585874] mtd_readtest: testing page read
[ 6967.883287] mtd_readtest: finished
[ 6967.886943] =================================================
[ 7025.195054] 
[ 7025.196667] =================================================
[ 7025.202864] mtd_speedtest: MTD device: 8
[ 7025.207034] mtd_speedtest: MTD device size 514850816, eraseblock size 131072, page size 2048, count of eraseblocks 3928, pages per eraseblock 64, OOB size 64
[ 7025.224291] mtd_test: scanning for bad eraseblocks
[ 7025.370595] mtd_test: block 1340 is bad
[ 7025.646751] mtd_test: scanned 3928 eraseblocks, 1 are bad
[ 7030.488338] mtd_speedtest: testing eraseblock write speed
[ 7140.166002] mtd_speedtest: eraseblock write speed is 4583 KiB/s
[ 7140.172475] mtd_speedtest: testing eraseblock read speed
[ 7213.757488] mtd_speedtest: eraseblock read speed is 6831 KiB/s
[ 7218.597280] mtd_speedtest: testing page write speed
[ 7328.597748] mtd_speedtest: page write speed is 4569 KiB/s
[ 7328.603517] mtd_speedtest: testing page read speed
[ 7402.403578] mtd_speedtest: page read speed is 6811 KiB/s
[ 7407.243084] mtd_speedtest: testing 2 page write speed
[ 7516.946841] mtd_speedtest: 2 page write speed is 4582 KiB/s
[ 7516.952792] mtd_speedtest: testing 2 page read speed
[ 7590.637384] mtd_speedtest: 2 page read speed is 6822 KiB/s
[ 7590.643247] mtd_speedtest: Testing erase speed
[ 7595.481133] mtd_speedtest: erase speed is 103983 KiB/s
[ 7595.486589] mtd_speedtest: Testing 2x multi-block erase speed
[ 7600.321512] mtd_speedtest: 2x multi-block erase speed is 104091 KiB/s
[ 7600.328339] mtd_speedtest: Testing 4x multi-block erase speed
[ 7605.160845] mtd_speedtest: 4x multi-block erase speed is 104155 KiB/s
[ 7605.167677] mtd_speedtest: Testing 8x multi-block erase speed
[ 7609.999327] mtd_speedtest: 8x multi-block erase speed is 104155 KiB/s
[ 7610.006178] mtd_speedtest: Testing 16x multi-block erase speed
[ 7614.837265] mtd_speedtest: 16x multi-block erase speed is 104177 KiB/s
[ 7614.844204] mtd_speedtest: Testing 32x multi-block erase speed
[ 7619.674561] mtd_speedtest: 32x multi-block erase speed is 104177 KiB/s
[ 7619.681524] mtd_speedtest: Testing 64x multi-block erase speed
[ 7624.511623] mtd_speedtest: 64x multi-block erase speed is 104199 KiB/s
[ 7624.518543] mtd_speedtest: finished
[ 7624.522255] =================================================
[ 7798.745134] 
[ 7798.746746] =================================================
[ 7798.752942] mtd_subpagetest: MTD device: 8
[ 7798.757295] mtd_subpagetest: MTD device size 514850816, eraseblock size 131072, page size 2048, subpage size 512, count of eraseblocks 3928, pages per eraseblock 64, OOB size 64
[ 7798.774100] mtd_test: scanning for bad eraseblocks
[ 7798.920247] mtd_test: block 1340 is bad
[ 7799.197142] mtd_test: scanned 3928 eraseblocks, 1 are bad
[ 7804.038474] mtd_subpagetest: writing whole device
[ 7804.044445] mtd_subpagetest: written up to eraseblock 0
[ 7804.291304] mtd_subpagetest: written up to eraseblock 256
[ 7804.537626] mtd_subpagetest: written up to eraseblock 512
[ 7804.783240] mtd_subpagetest: written up to eraseblock 768
[ 7805.031443] mtd_subpagetest: written up to eraseblock 1024
[ 7805.276172] mtd_subpagetest: written up to eraseblock 1280
[ 7805.519250] mtd_subpagetest: written up to eraseblock 1536
[ 7805.763137] mtd_subpagetest: written up to eraseblock 1792
[ 7806.006097] mtd_subpagetest: written up to eraseblock 2048
[ 7806.250634] mtd_subpagetest: written up to eraseblock 2304
[ 7806.495727] mtd_subpagetest: written up to eraseblock 2560
[ 7806.742410] mtd_subpagetest: written up to eraseblock 2816
[ 7806.989389] mtd_subpagetest: written up to eraseblock 3072
[ 7807.233751] mtd_subpagetest: written up to eraseblock 3328
[ 7807.479879] mtd_subpagetest: written up to eraseblock 3584
[ 7807.727727] mtd_subpagetest: written up to eraseblock 3840
[ 7807.814984] mtd_subpagetest: written 3928 eraseblocks
[ 7807.820326] mtd_subpagetest: verifying all eraseblocks
[ 7807.826078] mtd_subpagetest: verified up to eraseblock 0
[ 7807.902016] mtd_subpagetest: verified up to eraseblock 256
[ 7807.978402] mtd_subpagetest: verified up to eraseblock 512
[ 7808.054947] mtd_subpagetest: verified up to eraseblock 768
[ 7808.131268] mtd_subpagetest: verified up to eraseblock 1024
[ 7808.207516] mtd_subpagetest: verified up to eraseblock 1280
[ 7808.283511] mtd_subpagetest: verified up to eraseblock 1536
[ 7808.359755] mtd_subpagetest: verified up to eraseblock 1792
[ 7808.436017] mtd_subpagetest: verified up to eraseblock 2048
[ 7808.512282] mtd_subpagetest: verified up to eraseblock 2304
[ 7808.588528] mtd_subpagetest: verified up to eraseblock 2560
[ 7808.664823] mtd_subpagetest: verified up to eraseblock 2816
[ 7808.741110] mtd_subpagetest: verified up to eraseblock 3072
[ 7808.817332] mtd_subpagetest: verified up to eraseblock 3328
[ 7808.893566] mtd_subpagetest: verified up to eraseblock 3584
[ 7808.970056] mtd_subpagetest: verified up to eraseblock 3840
[ 7808.999924] mtd_subpagetest: verified 3928 eraseblocks
[ 7813.839104] mtd_subpagetest: verifying all eraseblocks for 0xff
[ 7813.878309] mtd_subpagetest: verified up to eraseblock 0
[ 7822.305635] mtd_subpagetest: verified up to eraseblock 256
[ 7830.727880] mtd_subpagetest: verified up to eraseblock 512
[ 7839.150819] mtd_subpagetest: verified up to eraseblock 768
[ 7847.572884] mtd_subpagetest: verified up to eraseblock 1024
[ 7855.998248] mtd_subpagetest: verified up to eraseblock 1280
[ 7864.389149] mtd_subpagetest: verified up to eraseblock 1536
[ 7872.811599] mtd_subpagetest: verified up to eraseblock 1792
[ 7881.235908] mtd_subpagetest: verified up to eraseblock 2048
[ 7889.659544] mtd_subpagetest: verified up to eraseblock 2304
[ 7898.083098] mtd_subpagetest: verified up to eraseblock 2560
[ 7906.505817] mtd_subpagetest: verified up to eraseblock 2816
[ 7914.934661] mtd_subpagetest: verified up to eraseblock 3072
[ 7923.361696] mtd_subpagetest: verified up to eraseblock 3328
[ 7931.786842] mtd_subpagetest: verified up to eraseblock 3584
[ 7940.210948] mtd_subpagetest: verified up to eraseblock 3840
[ 7943.077673] mtd_subpagetest: verified 3928 eraseblocks
[ 7943.083140] mtd_subpagetest: writing whole device
[ 7943.125404] mtd_subpagetest: written up to eraseblock 0
[ 7952.796846] mtd_subpagetest: written up to eraseblock 256
[ 7962.470818] mtd_subpagetest: written up to eraseblock 512
[ 7972.098018] mtd_subpagetest: written up to eraseblock 768
[ 7981.750299] mtd_subpagetest: written up to eraseblock 1024
[ 7991.369980] mtd_subpagetest: written up to eraseblock 1280
[ 8000.954801] mtd_subpagetest: written up to eraseblock 1536
[ 8010.565700] mtd_subpagetest: written up to eraseblock 1792
[ 8020.179393] mtd_subpagetest: written up to eraseblock 2048
[ 8029.801553] mtd_subpagetest: written up to eraseblock 2304
[ 8039.430975] mtd_subpagetest: written up to eraseblock 2560
[ 8049.077093] mtd_subpagetest: written up to eraseblock 2816
[ 8058.733850] mtd_subpagetest: written up to eraseblock 3072
[ 8068.346029] mtd_subpagetest: written up to eraseblock 3328
[ 8077.978313] mtd_subpagetest: written up to eraseblock 3584
[ 8087.635786] mtd_subpagetest: written up to eraseblock 3840
[ 8090.920974] mtd_subpagetest: written 3928 eraseblocks
[ 8090.926339] mtd_subpagetest: verifying all eraseblocks
[ 8090.955668] mtd_subpagetest: verified up to eraseblock 0
[ 8097.052051] mtd_subpagetest: verified up to eraseblock 256
[ 8103.149545] mtd_subpagetest: verified up to eraseblock 512
[ 8109.246688] mtd_subpagetest: verified up to eraseblock 768
[ 8115.343641] mtd_subpagetest: verified up to eraseblock 1024
[ 8121.440893] mtd_subpagetest: verified up to eraseblock 1280
[ 8127.514642] mtd_subpagetest: verified up to eraseblock 1536
[ 8133.612168] mtd_subpagetest: verified up to eraseblock 1792
[ 8139.708696] mtd_subpagetest: verified up to eraseblock 2048
[ 8145.805417] mtd_subpagetest: verified up to eraseblock 2304
[ 8151.902275] mtd_subpagetest: verified up to eraseblock 2560
[ 8157.999851] mtd_subpagetest: verified up to eraseblock 2816
[ 8164.099112] mtd_subpagetest: verified up to eraseblock 3072
[ 8170.197316] mtd_subpagetest: verified up to eraseblock 3328
[ 8176.294134] mtd_subpagetest: verified up to eraseblock 3584
[ 8182.391904] mtd_subpagetest: verified up to eraseblock 3840
[ 8184.467940] mtd_subpagetest: verified 3928 eraseblocks
[ 8189.306951] mtd_subpagetest: verifying all eraseblocks for 0xff
[ 8189.346161] mtd_subpagetest: verified up to eraseblock 0
[ 8197.770209] mtd_subpagetest: verified up to eraseblock 256
[ 8206.193309] mtd_subpagetest: verified up to eraseblock 512
[ 8214.616663] mtd_subpagetest: verified up to eraseblock 768
[ 8223.040804] mtd_subpagetest: verified up to eraseblock 1024
[ 8231.464029] mtd_subpagetest: verified up to eraseblock 1280
[ 8239.853503] mtd_subpagetest: verified up to eraseblock 1536
[ 8248.277585] mtd_subpagetest: verified up to eraseblock 1792
[ 8256.700477] mtd_subpagetest: verified up to eraseblock 2048
[ 8265.124269] mtd_subpagetest: verified up to eraseblock 2304
[ 8273.549314] mtd_subpagetest: verified up to eraseblock 2560
[ 8281.971823] mtd_subpagetest: verified up to eraseblock 2816
[ 8290.396009] mtd_subpagetest: verified up to eraseblock 3072
[ 8298.818985] mtd_subpagetest: verified up to eraseblock 3328
[ 8307.241174] mtd_subpagetest: verified up to eraseblock 3584
[ 8315.663750] mtd_subpagetest: verified up to eraseblock 3840
[ 8318.531406] mtd_subpagetest: verified 3928 eraseblocks
[ 8318.536862] mtd_subpagetest: finished with 0 errors
[ 8318.542045] =================================================
[ 8335.008839] 
[ 8335.010601] =================================================
[ 8335.016681] mtd_torturetest: Warning: this program is trying to wear out your flash, stop it if this is not wanted.
[ 8335.027742] mtd_torturetest: MTD device: 8
[ 8335.032123] mtd_torturetest: torture 32 eraseblocks (8-39) of mtd8
[ 8335.038661] mtd_torturetest: write verify enabled
[ 8335.045299] mtd_test: scanning for bad eraseblocks
[ 8335.053827] mtd_test: scanned 32 eraseblocks, 0 are bad
[ 9502.026753] mtd_torturetest: 00000512 erase cycles done, took 1166968 milliseconds (1166 seconds)
[10668.222020] mtd_torturetest: 00001024 erase cycles done, took 1166185 milliseconds (1166 seconds)
[11834.145009] mtd_torturetest: 00001536 erase cycles done, took 1165914 milliseconds (1165 seconds)
[13000.026525] mtd_torturetest: 00002048 erase cycles done, took 1165872 milliseconds (1165 seconds)
[14165.809096] mtd_torturetest: 00002560 erase cycles done, took 1165774 milliseconds (1165 seconds)
[15331.465312] mtd_torturetest: 00003072 erase cycles done, took 1165647 milliseconds (1165 seconds)
[16497.275516] mtd_torturetest: 00003584 erase cycles done, took 1165801 milliseconds (1165 seconds)
[17663.120327] mtd_torturetest: 00004096 erase cycles done, took 1165835 milliseconds (1165 seconds)
[18829.000457] mtd_torturetest: 00004608 erase cycles done, took 1165871 milliseconds (1165 seconds)
[19994.773017] mtd_torturetest: 00005120 erase cycles done, took 1165764 milliseconds (1165 seconds)
[21160.463390] mtd_torturetest: 00005632 erase cycles done, took 1165681 milliseconds (1165 seconds)
[22325.979282] mtd_torturetest: 00006144 erase cycles done, took 1165506 milliseconds (1165 seconds)
[23491.261117] mtd_torturetest: 00006656 erase cycles done, took 1165273 milliseconds (1165 seconds)
[24656.408780] mtd_torturetest: 00007168 erase cycles done, took 1165138 milliseconds (1165 seconds)
[25821.714340] mtd_torturetest: 00007680 erase cycles done, took 1165296 milliseconds (1165 seconds)
[26986.890994] mtd_torturetest: 00008192 erase cycles done, took 1165167 milliseconds (1165 seconds)
[28151.902202] mtd_torturetest: 00008704 erase cycles done, took 1165001 milliseconds (1165 seconds)
[29316.726816] mtd_torturetest: 00009216 erase cycles done, took 1164816 milliseconds (1164 seconds)
[30481.418017] mtd_torturetest: 00009728 erase cycles done, took 1164682 milliseconds (1164 seconds)
[31645.981594] mtd_torturetest: 00010240 erase cycles done, took 1164554 milliseconds (1164 seconds)
[32810.300968] mtd_torturetest: 00010752 erase cycles done, took 1164310 milliseconds (1164 seconds)
[33974.410349] mtd_torturetest: 00011264 erase cycles done, took 1164099 milliseconds (1164 seconds)
[35139.050210] mtd_torturetest: 00011776 erase cycles done, took 1164630 milliseconds (1164 seconds)
[36303.022338] mtd_torturetest: 00012288 erase cycles done, took 1163963 milliseconds (1163 seconds)
[37466.787286] mtd_torturetest: 00012800 erase cycles done, took 1163756 milliseconds (1163 seconds)
[38630.303651] mtd_torturetest: 00013312 erase cycles done, took 1163507 milliseconds (1163 seconds)
[39793.428639] mtd_torturetest: 00013824 erase cycles done, took 1163115 milliseconds (1163 seconds)
[40956.256751] mtd_torturetest: 00014336 erase cycles done, took 1162818 milliseconds (1162 seconds)
[42118.613025] mtd_torturetest: 00014848 erase cycles done, took 1162346 milliseconds (1162 seconds)
[43280.857584] mtd_torturetest: 00015360 erase cycles done, took 1162235 milliseconds (1162 seconds)
[44442.698340] mtd_torturetest: 00015872 erase cycles done, took 1161832 milliseconds (1161 seconds)
[45603.874380] mtd_torturetest: 00016384 erase cycles done, took 1161166 milliseconds (1161 seconds)
[46764.711606] mtd_torturetest: 00016896 erase cycles done, took 1160828 milliseconds (1160 seconds)
[47925.129542] mtd_torturetest: 00017408 erase cycles done, took 1160408 milliseconds (1160 seconds)
[49085.138462] mtd_torturetest: 00017920 erase cycles done, took 1160000 milliseconds (1160 seconds)
[50244.865052] mtd_torturetest: 00018432 erase cycles done, took 1159718 milliseconds (1159 seconds)
[51404.290447] mtd_torturetest: 00018944 erase cycles done, took 1159416 milliseconds (1159 seconds)
[52563.613492] mtd_torturetest: 00019456 erase cycles done, took 1159313 milliseconds (1159 seconds)
[53722.606963] mtd_torturetest: 00019968 erase cycles done, took 1158984 milliseconds (1158 seconds)
[54881.250300] mtd_torturetest: 00020480 erase cycles done, took 1158633 milliseconds (1158 seconds)
[56039.484560] mtd_torturetest: 00020992 erase cycles done, took 1158224 milliseconds (1158 seconds)
[57197.368672] mtd_torturetest: 00021504 erase cycles done, took 1157875 milliseconds (1157 seconds)
[58354.655187] mtd_torturetest: 00022016 erase cycles done, took 1157276 milliseconds (1157 seconds)
[59511.394870] mtd_torturetest: 00022528 erase cycles done, took 1156730 milliseconds (1156 seconds)
[60667.796448] mtd_torturetest: 00023040 erase cycles done, took 1156392 milliseconds (1156 seconds)
[61823.590801] mtd_torturetest: 00023552 erase cycles done, took 1155785 milliseconds (1155 seconds)
[62979.570519] mtd_torturetest: 00024064 erase cycles done, took 1155971 milliseconds (1155 seconds)
[64134.611033] mtd_torturetest: 00024576 erase cycles done, took 1155031 milliseconds (1155 seconds)
[65287.943710] mtd_torturetest: 00025088 erase cycles done, took 1153323 milliseconds (1153 seconds)


-- 
Mickael Chazaux
Software Engineer
Tel : (33) 476 042 006
Fax : (33) 476 042 001

ETIC TELECOM
13, Chemin du Vieux Chêne
38240 MEYLAN
Tel: 33 4 76 04 20 00
fax : 33 4 76 04 20 01

______________________________________________________
Linux MTD discussion mailing list
http://lists.infradead.org/mailman/listinfo/linux-mtd/

Re: ubifs_check_node: bad CRC

[Richard Weinberger]

On Tue, Jul 30, 2019 at 9:28 AM Mickael Chazaux
<mickael.chazaux@etictelecom.com> wrote:
> > That easy?
> > Hmm, sounds a bit like a bug in your NAND driver. Did you test it?
> >
>
> Sorry, I meant : the "nand-image.img" file is coming from a corrupted device.
> I ran the mtd_* kernel module tests yesterday. All seems good, but the torture test
> is not yet finished (see below).

Ahh, now it makes more sense.

> The problem occured in the field on several devices, and I cannot reproduce it
> in the lab.

It sounds a bit like a memory corruption.

> > Please also disable compression in UBIFS, then the read back data maybe gives
> > you a hint what went wrong.
>
> In the corrupted node I see data from syslog. This system is a bit different
> than the others we usually make, as there are more power cuts and more log writes.

Hmm. Power cuts or many writes should not trigger such a corruption.
I'd expect ECC errors or data structure errors in UBIFS. But not a good ECC
with bad UBIFS data CRC.

But with only one sample it is almost impossible to figure...

-- 
Thanks,
//richard

______________________________________________________
Linux MTD discussion mailing list
http://lists.infradead.org/mailman/listinfo/linux-mtd/

Re: ubifs_check_node: bad CRC

[Mickael Chazaux]

On 13/08/2019 23:41, Richard Weinberger wrote:

> 
>> The problem occured in the field on several devices, and I cannot reproduce it
>> in the lab.
> 
> It sounds a bit like a memory corruption.
> 
>>> Please also disable compression in UBIFS, then the read back data maybe gives
>>> you a hint what went wrong.
>>
>> In the corrupted node I see data from syslog. This system is a bit different
>> than the others we usually make, as there are more power cuts and more log writes.
> 
> Hmm. Power cuts or many writes should not trigger such a corruption.
> I'd expect ECC errors or data structure errors in UBIFS. But not a good ECC
> with bad UBIFS data CRC.
> 
> But with only one sample it is almost impossible to figure...
> 

Memory corruption as in some kind of buffer overflow or use after free ? or physical 
bus errors? Anyway I think I will implement some mitigations at the application level, 
(eg. less log messages, recovery by creating a new volume, copy the now-readonly data, 
rename the volume) because the haystack just got too big for the needle.

Thank you for your help,

Mickael

-- 
Mickael Chazaux
Software Engineer
Tel : (33) 476 042 006
Fax : (33) 476 042 001

ETIC TELECOM
13, Chemin du Vieux Chêne
38240 MEYLAN
Tel: 33 4 76 04 20 00
fax : 33 4 76 04 20 01

______________________________________________________
Linux MTD discussion mailing list
http://lists.infradead.org/mailman/listinfo/linux-mtd/

Re: ubifs_check_node: bad CRC

[Richard Weinberger]

On Fri, Aug 23, 2019 at 11:25 AM Mickael Chazaux
<mickael.chazaux@etictelecom.com> wrote:
> > Hmm. Power cuts or many writes should not trigger such a corruption.
> > I'd expect ECC errors or data structure errors in UBIFS. But not a good ECC
> > with bad UBIFS data CRC.
> >
> > But with only one sample it is almost impossible to figure...
> >
>
> Memory corruption as in some kind of buffer overflow or use after free ? or physical
> bus errors? Anyway I think I will implement some mitigations at the application level,
> (eg. less log messages, recovery by creating a new volume, copy the now-readonly data,
> rename the volume) because the haystack just got too big for the needle.

This could be caused my any kind of corruption. Do you monitor your devices?
Maybe the crash also once in a while and you notice only the case when bad data
is written to flash.

-- 
Thanks,
//richard

______________________________________________________
Linux MTD discussion mailing list
http://lists.infradead.org/mailman/listinfo/linux-mtd/