Re: ECC errors after UBI writes with brcmnand (Northstar with v6.1 controller)

Rafał Miłecki
2022-03-24T16:49:43Z

On 18.03.2022 19:02, Rafał Miłecki wrote:
> My problem is that ubifs complains about ECC errors. I spent some time
> debugging it and it seems that:
> 1. Initially all blocks written by bootloader can be read fine
> 2. Few blocks written by ubifs -> ubi -> brcmnand can't be read back

I reproduced this problem with:
1. MTD partition erased by OpenWrt
2. Firmware flashed using "nandwrite"
3. Mounting UBI volume with ubifs twice

root@(none):/# mtd erase firmware
Unlocking firmware ...
Erasing firmware ...

Skipping bad block at 0x5c40000
Skipping bad block at 0x12dc0000
Skipping bad block at 0x1d8e0000
Skipping bad block at 0x1d920000

root@(none):/# nandwrite /dev/mtd0 /tmp/bcm*trx
Writing data to block 0 at offset 0x0
Writing data to block 1 at offset 0x20000
Writing data to block 2 at offset 0x40000
Writing data to block 3 at offset 0x60000
Writing data to block 4 at offset 0x80000
Writing data to block 5 at offset 0xa0000
Writing data to block 6 at offset 0xc0000
Writing data to block 7 at offset 0xe0000
Writing data to block 8 at offset 0x100000
Writing data to block 9 at offset 0x120000
Writing data to block 10 at offset 0x140000
Writing data to block 11 at offset 0x160000
Writing data to block 12 at offset 0x180000
Writing data to block 13 at offset 0x1a0000
Writing data to block 14 at offset 0x1c0000
Writing data to block 15 at offset 0x1e0000
Writing data to block 16 at offset 0x200000
Writing data to block 17 at offset 0x220000
Writing data to block 18 at offset 0x240000
Writing data to block 19 at offset 0x260000
Writing data to block 20 at offset 0x280000
Writing data to block 21 at offset 0x2a0000
Writing data to block 22 at offset 0x2c0000
Writing data to block 23 at offset 0x2e0000
Writing data to block 24 at offset 0x300000
Writing data to block 25 at offset 0x320000
Writing data to block 26 at offset 0x340000
Writing data to block 27 at offset 0x360000
Writing data to block 28 at offset 0x380000
Writing data to block 29 at offset 0x3a0000
Writing data to block 30 at offset 0x3c0000
Writing data to block 31 at offset 0x3e0000
Writing data to block 32 at offset 0x400000
Writing data to block 33 at offset 0x420000
Writing data to block 34 at offset 0x440000
Writing data to block 35 at offset 0x460000
Writing data to block 36 at offset 0x480000
Writing data to block 37 at offset 0x4a0000
Writing data to block 38 at offset 0x4c0000
Writing data to block 39 at offset 0x4e0000
Writing data to block 40 at offset 0x500000
Writing data to block 41 at offset 0x520000
Writing data to block 42 at offset 0x540000
Writing data to block 43 at offset 0x560000
Writing data to block 44 at offset 0x580000
Writing data to block 45 at offset 0x5a0000
Writing data to block 46 at offset 0x5c0000
Writing data to block 47 at offset 0x5e0000
Writing data to block 48 at offset 0x600000
Writing data to block 49 at offset 0x620000
Writing data to block 50 at offset 0x640000
Writing data to block 51 at offset 0x660000
Writing data to block 52 at offset 0x680000
Writing data to block 53 at offset 0x6a0000
Writing data to block 54 at offset 0x6c0000
Writing data to block 55 at offset 0x6e0000
Writing data to block 56 at offset 0x700000
Writing data to block 57 at offset 0x720000
Writing data to block 58 at offset 0x740000
Writing data to block 59 at offset 0x760000
Writing data to block 60 at offset 0x780000
Writing data to block 61 at offset 0x7a0000
Writing data to block 62 at offset 0x7c0000
Writing data to block 63 at offset 0x7e0000
Writing data to block 64 at offset 0x800000
Writing data to block 65 at offset 0x820000
Writing data to block 66 at offset 0x840000
Writing data to block 67 at offset 0x860000
Writing data to block 68 at offset 0x880000
Writing data to block 69 at offset 0x8a0000
Writing data to block 70 at offset 0x8c0000
Writing data to block 71 at offset 0x8e0000
Writing data to block 72 at offset 0x900000
Writing data to block 73 at offset 0x920000
Writing data to block 74 at offset 0x940000
Writing data to block 75 at offset 0x960000
Writing data to block 76 at offset 0x980000
Writing data to block 77 at offset 0x9a0000
Writing data to block 78 at offset 0x9c0000
Writing data to block 79 at offset 0x9e0000
Writing data to block 80 at offset 0xa00000
Writing data to block 81 at offset 0xa20000
Writing data to block 82 at offset 0xa40000
Writing data to block 83 at offset 0xa60000
Writing data to block 84 at offset 0xa80000
Writing data to block 85 at offset 0xaa0000
Writing data to block 86 at offset 0xac0000
Writing data to block 87 at offset 0xae0000
Writing data to block 88 at offset 0xb00000
Writing data to block 89 at offset 0xb20000
Writing data to block 90 at offset 0xb40000
Writing data to block 91 at offset 0xb60000
Writing data to block 92 at offset 0xb80000
Writing data to block 93 at offset 0xba0000
Writing data to block 94 at offset 0xbc0000
Writing data to block 95 at offset 0xbe0000
Writing data to block 96 at offset 0xc00000
Writing data to block 97 at offset 0xc20000
Writing data to block 98 at offset 0xc40000
Writing data to block 99 at offset 0xc60000
Writing data to block 100 at offset 0xc80000
Writing data to block 101 at offset 0xca0000
Writing data to block 102 at offset 0xcc0000
Writing data to block 103 at offset 0xce0000
Writing data to block 104 at offset 0xd00000
Writing data to block 105 at offset 0xd20000
Writing data to block 106 at offset 0xd40000
Writing data to block 107 at offset 0xd60000
Writing data to block 108 at offset 0xd80000
Writing data to block 109 at offset 0xda0000
Writing data to block 110 at offset 0xdc0000
Writing data to block 111 at offset 0xde0000
Writing data to block 112 at offset 0xe00000
Writing data to block 113 at offset 0xe20000
Writing data to block 114 at offset 0xe40000
Writing data to block 115 at offset 0xe60000
Writing data to block 116 at offset 0xe80000
Writing data to block 117 at offset 0xea0000
Writing data to block 118 at offset 0xec0000
Writing data to block 119 at offset 0xee0000
Writing data to block 120 at offset 0xf00000
Writing data to block 121 at offset 0xf20000
Writing data to block 122 at offset 0xf40000
Writing data to block 123 at offset 0xf60000
Writing data to block 124 at offset 0xf80000
Writing data to block 125 at offset 0xfa0000
Writing data to block 126 at offset 0xfc0000
Writing data to block 127 at offset 0xfe0000
Writing data to block 128 at offset 0x1000000
Writing data to block 129 at offset 0x1020000
Writing data to block 130 at offset 0x1040000
Writing data to block 131 at offset 0x1060000
Writing data to block 132 at offset 0x1080000
Writing data to block 133 at offset 0x10a0000
Writing data to block 134 at offset 0x10c0000
Writing data to block 135 at offset 0x10e0000
Writing data to block 136 at offset 0x1100000
Writing data to block 137 at offset 0x1120000
Writing data to block 138 at offset 0x1140000
Writing data to block 139 at offset 0x1160000
Writing data to block 140 at offset 0x1180000
Writing data to block 141 at offset 0x11a0000
Writing data to block 142 at offset 0x11c0000
Writing data to block 143 at offset 0x11e0000

root@(none):/# ubiattach -m 3
[ 38.455190] ubi1: attaching mtd3
[ 39.472842] ubi1: scanning is finished
[ 39.503069] ubi1: volume 0 ("rootfs") re-sized from 122 to 2968 LEBs
[ 39.510246] ubi1: attached mtd3 (name "ubi2", size 381 MiB)
[ 39.515843] ubi1: PEB size: 131072 bytes (128 KiB), LEB size: 126976 bytes
[ 39.522759] ubi1: min./max. I/O unit sizes: 2048/2048, sub-page size 2048
[ 39.529576] ubi1: VID header offset: 2048 (aligned 2048), data offset: 4096
[ 39.536548] ubi1: good PEBs: 3050, bad PEBs: 2, corrupted PEBs: 0
[ 39.542657] ubi1: user volume: 1, internal volumes: 1, max. volumes count: 128
[ 39.549907] ubi1: max/mean erase counter: 1/0, WL threshold: 4096, image sequence number: 1483550259
[ 39.559070] ubi1: available PEBs: 0, total reserved PEBs: 3050, PEBs reserved for bad PEB handling: 78
[ 39.568430] ubi1: background thread "ubi_bgt1d" started, PID 644
UBI device number 1, total 3050 LEBs (387276800 bytes, 369.3 MiB), available 0 LEBs (0 bytes), LEB size 126976 bytes (124.0 KiB)

root@(none):/# mknod -m 0600 /dev/ubi1_0 c 251 1

root@(none):/# mount -t ubifs /dev/ubi1_0 /mnt/
[ 46.084422] UBIFS (ubi1:0): Mounting in unauthenticated mode
[ 46.090255] UBIFS (ubi1:0): background thread "ubifs_bgt1_0" started, PID 648
[ 46.177436] UBIFS (ubi1:0): UBIFS: mounted UBI device 1, volume 0, name "rootfs"
[ 46.184856] UBIFS (ubi1:0): LEB size: 126976 bytes (124 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes
[ 46.194824] UBIFS (ubi1:0): FS size: 258650112 bytes (246 MiB, 2037 LEBs), journal size 9023488 bytes (8 MiB, 72 LEBs)
[ 46.205560] UBIFS (ubi1:0): reserved for root: 0 bytes (0 KiB)
[ 46.211430] UBIFS (ubi1:0): media format: w4/r0 (latest is w5/r0), UUID 99F16624-3626-45C3-AD59-18C8F923A56D, small LPT model

root@(none):/# ls /mnt/etc/
dropbear init.d mtab profile.d shells
fstab inittab network protocols ssl
group iptables.conf os-release resolv.conf
hostname issue passwd services
hosts mdev.conf profile shadow

root@(none):/# umount /mnt/
[ 53.678051] UBIFS (ubi1:0): un-mount UBI device 1
[ 53.682868] UBIFS (ubi1:0): background thread "ubifs_bgt1_0" stops

root@(none):/# mount -t ubifs /dev/ubi1_0 /mnt/
[ 56.054517] UBIFS (ubi1:0): Mounting in unauthenticated mode
[ 56.060345] UBIFS (ubi1:0): background thread "ubifs_bgt1_0" started, PID 654
[ 56.081148] ubi1 warning: ubi_io_read: error -74 (ECC error) while reading 126976 bytes from PEB 3:4096, read only 126976 bytes, retry
[ 56.114079] ubi1 warning: ubi_io_read: error -74 (ECC error) while reading 126976 bytes from PEB 3:4096, read only 126976 bytes, retry
[ 56.146967] ubi1 warning: ubi_io_read: error -74 (ECC error) while reading 126976 bytes from PEB 3:4096, read only 126976 bytes, retry
[ 56.179825] ubi1 error: ubi_io_read: error -74 (ECC error) while reading 126976 bytes from PEB 3:4096, read 126976 bytes
[ 56.190741] CPU: 0 PID: 652 Comm: mount Not tainted 5.10.100 #0
[ 56.196671] Hardware name: BCM5301X
[ 56.200187] [<c010871c>] (unwind_backtrace) from [<c0104c4c>] (show_stack+0x10/0x14)
[ 56.207957] [<c0104c4c>] (show_stack) from [<c03e7f08>] (dump_stack+0x94/0xa8)
[ 56.215201] [<c03e7f08>] (dump_stack) from [<c04b2ef4>] (ubi_io_read+0x158/0x3dc)
[ 56.222700] [<c04b2ef4>] (ubi_io_read) from [<c04b0964>] (ubi_eba_read_leb+0xb0/0x470)
[ 56.230638] [<c04b0964>] (ubi_eba_read_leb) from [<c04af08c>] (ubi_leb_read+0x90/0x100)
[ 56.238677] [<c04af08c>] (ubi_leb_read) from [<c030aefc>] (ubifs_leb_read+0x2c/0x78)
[ 56.246439] [<c030aefc>] (ubifs_leb_read) from [<c0313ba0>] (ubifs_start_scan+0x88/0x10c)
[ 56.254633] [<c0313ba0>] (ubifs_start_scan) from [<c0313e2c>] (ubifs_scan+0x24/0x390)
[ 56.262484] [<c0313e2c>] (ubifs_scan) from [<c0312ec8>] (ubifs_read_master+0x40/0x870)
[ 56.270414] [<c0312ec8>] (ubifs_read_master) from [<c0308854>] (ubifs_mount+0xf80/0x1ed8)
[ 56.278625] [<c0308854>] (ubifs_mount) from [<c0290c84>] (legacy_get_tree+0x24/0x48)
[ 56.286395] [<c0290c84>] (legacy_get_tree) from [<c025c164>] (vfs_get_tree+0x24/0xe4)
[ 56.294250] [<c025c164>] (vfs_get_tree) from [<c028056c>] (path_mount+0x6e8/0xa90)
[ 56.301836] [<c028056c>] (path_mount) from [<c0280dd8>] (sys_mount+0x144/0x214)
[ 56.309164] [<c0280dd8>] (sys_mount) from [<c0100040>] (ret_fast_syscall+0x0/0x54)
[ 56.316743] Exception stack(0xc1adffa8 to 0xc1adfff0)
[ 56.321802] ffa0: 00000000 00008000 beea1c93 beea1c9f beea1c8d 00008000
[ 56.329992] ffc0: 00000000 00008000 00008000 00000015 b6f703ac 000865f0 000865d8 00000000
[ 56.338190] ffe0: 00085d44 beea1720 0003c2e0 b6f023ac
[ 56.364422] ubi1 warning: ubi_io_read: error -74 (ECC error) while reading 126976 bytes from PEB 4:4096, read only 126976 bytes, retry
[ 56.397292] ubi1 warning: ubi_io_read: error -74 (ECC error) while reading 126976 bytes from PEB 4:4096, read only 126976 bytes, retry
[ 56.430143] ubi1 warning: ubi_io_read: error -74 (ECC error) while reading 126976 bytes from PEB 4:4096, read only 126976 bytes, retry
[ 56.462993] ubi1 error: ubi_io_read: error -74 (ECC error) while reading 126976 bytes from PEB 4:4096, read 126976 bytes
[ 56.473900] CPU: 0 PID: 652 Comm: mount Not tainted 5.10.100 #0
[ 56.479828] Hardware name: BCM5301X
[ 56.483338] [<c010871c>] (unwind_backtrace) from [<c0104c4c>] (show_stack+0x10/0x14)
[ 56.491103] [<c0104c4c>] (show_stack) from [<c03e7f08>] (dump_stack+0x94/0xa8)
[ 56.498348] [<c03e7f08>] (dump_stack) from [<c04b2ef4>] (ubi_io_read+0x158/0x3dc)
[ 56.505851] [<c04b2ef4>] (ubi_io_read) from [<c04b0964>] (ubi_eba_read_leb+0xb0/0x470)
[ 56.513787] [<c04b0964>] (ubi_eba_read_leb) from [<c04af08c>] (ubi_leb_read+0x90/0x100)
[ 56.521824] [<c04af08c>] (ubi_leb_read) from [<c030aefc>] (ubifs_leb_read+0x2c/0x78)
[ 56.529588] [<c030aefc>] (ubifs_leb_read) from [<c0313ba0>] (ubifs_start_scan+0x88/0x10c)
[ 56.537782] [<c0313ba0>] (ubifs_start_scan) from [<c0313e2c>] (ubifs_scan+0x24/0x390)
[ 56.545625] [<c0313e2c>] (ubifs_scan) from [<c0312f28>] (ubifs_read_master+0xa0/0x870)
[ 56.553564] [<c0312f28>] (ubifs_read_master) from [<c0308854>] (ubifs_mount+0xf80/0x1ed8)
[ 56.561774] [<c0308854>] (ubifs_mount) from [<c0290c84>] (legacy_get_tree+0x24/0x48)
[ 56.569543] [<c0290c84>] (legacy_get_tree) from [<c025c164>] (vfs_get_tree+0x24/0xe4)
[ 56.577391] [<c025c164>] (vfs_get_tree) from [<c028056c>] (path_mount+0x6e8/0xa90)
[ 56.584977] [<c028056c>] (path_mount) from [<c0280dd8>] (sys_mount+0x144/0x214)
[ 56.592305] [<c0280dd8>] (sys_mount) from [<c0100040>] (ret_fast_syscall+0x0/0x54)
[ 56.599893] Exception stack(0xc1adffa8 to 0xc1adfff0)
[ 56.604951] ffa0: 00000000 00008000 beea1c93 beea1c9f beea1c8d 00008000
[ 56.613142] ffc0: 00000000 00008000 00008000 00000015 b6f703ac 000865f0 000865d8 00000000
[ 56.621331] ffe0: 00085d44 beea1720 0003c2e0 b6f023ac
[ 56.627810] ubi1 warning: ubi_io_read: error -74 (ECC error) while reading 11 bytes from PEB 10:6144, read only 11 bytes, retry
[ 56.639956] ubi1 warning: ubi_io_read: error -74 (ECC error) while reading 11 bytes from PEB 10:6144, read only 11 bytes, retry
[ 56.652083] ubi1 warning: ubi_io_read: error -74 (ECC error) while reading 11 bytes from PEB 10:6144, read only 11 bytes, retry
[ 56.664214] ubi1 error: ubi_io_read: error -74 (ECC error) while reading 11 bytes from PEB 10:6144, read 11 bytes
[ 56.674504] CPU: 0 PID: 652 Comm: mount Not tainted 5.10.100 #0
[ 56.680429] Hardware name: BCM5301X
[ 56.683934] [<c010871c>] (unwind_backtrace) from [<c0104c4c>] (show_stack+0x10/0x14)
[ 56.691702] [<c0104c4c>] (show_stack) from [<c03e7f08>] (dump_stack+0x94/0xa8)
[ 56.698941] [<c03e7f08>] (dump_stack) from [<c04b2ef4>] (ubi_io_read+0x158/0x3dc)
[ 56.706442] [<c04b2ef4>] (ubi_io_read) from [<c04b0964>] (ubi_eba_read_leb+0xb0/0x470)
[ 56.714380] [<c04b0964>] (ubi_eba_read_leb) from [<c04af08c>] (ubi_leb_read+0x90/0x100)
[ 56.722414] [<c04af08c>] (ubi_leb_read) from [<c030aefc>] (ubifs_leb_read+0x2c/0x78)
[ 56.730186] [<c030aefc>] (ubifs_leb_read) from [<c0322a00>] (ubifs_lpt_init+0x1d0/0x998)
[ 56.738298] [<c0322a00>] (ubifs_lpt_init) from [<c0308908>] (ubifs_mount+0x1034/0x1ed8)
[ 56.746332] [<c0308908>] (ubifs_mount) from [<c0290c84>] (legacy_get_tree+0x24/0x48)
[ 56.754101] [<c0290c84>] (legacy_get_tree) from [<c025c164>] (vfs_get_tree+0x24/0xe4)
[ 56.761950] [<c025c164>] (vfs_get_tree) from [<c028056c>] (path_mount+0x6e8/0xa90)
[ 56.769536] [<c028056c>] (path_mount) from [<c0280dd8>] (sys_mount+0x144/0x214)
[ 56.776865] [<c0280dd8>] (sys_mount) from [<c0100040>] (ret_fast_syscall+0x0/0x54)
[ 56.784452] Exception stack(0xc1adffa8 to 0xc1adfff0)
[ 56.789512] ffa0: 00000000 00008000 beea1c93 beea1c9f beea1c8d 00008000
[ 56.797710] ffc0: 00000000 00008000 00008000 00000015 b6f703ac 000865f0 000865d8 00000000
[ 56.805899] ffe0: 00085d44 beea1720 0003c2e0 b6f023ac
[ 56.810998] UBIFS error (ubi1:0 pid 652): ubifs_leb_read: reading 11 bytes from LEB 8:2048 failed, error -74
[ 56.820858] CPU: 0 PID: 652 Comm: mount Not tainted 5.10.100 #0
[ 56.826787] Hardware name: BCM5301X
[ 56.830287] [<c010871c>] (unwind_backtrace) from [<c0104c4c>] (show_stack+0x10/0x14)
[ 56.838049] [<c0104c4c>] (show_stack) from [<c03e7f08>] (dump_stack+0x94/0xa8)
[ 56.845289] [<c03e7f08>] (dump_stack) from [<c030af44>] (ubifs_leb_read+0x74/0x78)
[ 56.852879] [<c030af44>] (ubifs_leb_read) from [<c0322a00>] (ubifs_lpt_init+0x1d0/0x998)
[ 56.860989] [<c0322a00>] (ubifs_lpt_init) from [<c0308908>] (ubifs_mount+0x1034/0x1ed8)
[ 56.869019] [<c0308908>] (ubifs_mount) from [<c0290c84>] (legacy_get_tree+0x24/0x48)
[ 56.876780] [<c0290c84>] (legacy_get_tree) from [<c025c164>] (vfs_get_tree+0x24/0xe4)
[ 56.884630] [<c025c164>] (vfs_get_tree) from [<c028056c>] (path_mount+0x6e8/0xa90)
[ 56.892219] [<c028056c>] (path_mount) from [<c0280dd8>] (sys_mount+0x144/0x214)
[ 56.899548] [<c0280dd8>] (sys_mount) from [<c0100040>] (ret_fast_syscall+0x0/0x54)
[ 56.907134] Exception stack(0xc1adffa8 to 0xc1adfff0)
[ 56.912193] ffa0: 00000000 00008000 beea1c93 beea1c9f beea1c8d 00008000
[ 56.920384] ffc0: 00000000 00008000 00008000 00000015 b6f703ac 000865f0 000865d8 00000000
[ 56.928574] ffe0: 00085d44 beea1720 0003c2e0 b6f023ac
[ 56.933684] UBIFS (ubi1:0): background thread "ubifs_bgt1_0" stops
mount: mounting /dev/ubi1_0 on /mnt/ failed: Bad message