PXA310: double bit errors on NAND

Bjørn Forsman bjorn.forsman at gmail.com
Mon Nov 8 11:54:03 EST 2010


2010/11/8 Bjørn Forsman <bjorn.forsman at gmail.com>:
> Hi all,
>
> I get "double bit error @ page" messages while working with NAND on a
> Colibri PXA310 module. Basically, when I write an UBI image to NAND,
> either with U-Boot "nand write" or "nandwrite" from mtd-utils,
> everything is OK on the *first* mount. But on the second mount I get
> several "double bit error @ page" messages and mount fails. This
> always happen (unless I'm mounting read-only -- then the problem is
> gone). But the funny thing is that if I write an UBIFS image using
> these commands:
>
> ubiformat /dev/mtd7
> ubiattach -m 7
> ubimkvol /dev/ubi0 -N rootfs -m
> ubiupdatevol /dev/ubi0_0 /rootfs.ubifs
>
> everything is OK! I can mount/umount many times and no errors.

After reading the MTD how to send bugreport[1] (which I should have
read earlier!) I enabled "UBI debugging messages" and "Extra
self-checks". The console output is now much more useful :-) AFAICS,
it shows that UBI fails to write data to PEB 3 and switches to
read-only mode. UBIFS then reports write failure at LEB 1 and then the
kernel tries to dereference a NULL pointer:

# flash_eraseall /dev/mtd7 && nandwrite -p /dev/mtd7 /rootfs.ubi
# ubiattach -m 7
# mount -t ubifs /dev/ubi0_0 /mnt
[  664.964427] UBI warning: ubi_eba_write_leb: failed to write data to PEB 3
[  664.971275] UBI warning: ubi_ro_mode: switch to read-only mode
[  664.977087] UBIFS error (pid 1014): ubifs_write_node: cannot write
2048 bytes to LEB 1:2048, error 5
[  665.008605] kernel BUG at fs/super.c:948!
[  665.012616] Unable to handle kernel NULL pointer dereference at
virtual address 00000000
[  665.020789] pgd = c6888000
[  665.023484] [00000000] *pgd=a7ba0031, *pte=00000000, *ppte=00000000
[  665.029782] Internal error: Oops: 817 [#1] PREEMPT
[  665.034537] last sysfs file: /sys/devices/virtual/ubi/ubi0/min_io_size
[  665.041017] Modules linked in:
[  665.044055] CPU: 0    Not tainted  (2.6.36-00018-g14edd22-dirty #265)
[  665.050467] PC is at __bug+0x24/0x30
[  665.054031] LR is at release_console_sem+0x1e8/0x200
[  665.058968] pc : [<c002b9e0>]    lr : [<c0040454>]    psr: 60000013
[  665.058981] sp : c6873ec0  ip : c6873df0  fp : c6873ecc
[  665.070370] r10: c686b000  r9 : c689cbe0  r8 : c686b000
[  665.075557] r7 : 00008000  r6 : 00000005  r5 : c03e5cd8  r4 : c7b1f000
[  665.082044] r3 : 00000000  r2 : 00000001  r1 : c6873e18  r0 : 00000033
[  665.088526] Flags: nZCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment user
[  665.095614] Control: 0000397f  Table: a6888018  DAC: 00000015
[  665.101317] Process mount (pid: 1014, stack limit = 0xc6872278)
[  665.107201] Stack: (0xc6873ec0 to 0xc6874000)
[  665.111540] 3ec0: c6873efc c6873ed0 c00a4d38 c002b9c8 c7b1f000
c6873ee0 c00bae28 c03e5cd8
[  665.119679] 3ee0: c689cbe0 c686b000 c689cbc0 00008000 c6873f24
c6873f00 c00a4e28 c00a4cc0
[  665.127811] 3f00: c686b000 00000020 c689cbc0 00000000 00000000
00008000 c6873f6c c6873f28
[  665.135944] 3f20: c00be030 c00a4df8 00000000 c6873f6c 00000000
c6873f48 c7805a00 c7452c00
[  665.144077] 3f40: 20000013 c7b9b000 be8f9eb8 00008000 00000000
c0028108 c6872000 00000000
[  665.152211] 3f60: c6873fa4 c6873f70 c00be140 c00bd9d4 c686b000
3a699d01 386d4604 c686b000
[  665.160342] 3f80: c689cbc0 c689cbe0 000b9018 be8f9c70 4018d380
00000015 00000000 c6873fa8
[  665.168476] 3fa0: c0027f60 c00be0c0 000b9018 be8f9c70 be8f9eb8
be8f9ec4 be8f9eb2 00008000
[  665.176607] 3fc0: 000b9018 be8f9c70 4018d380 00000015 00000000
0000d0b0 00008000 00000000
[  665.184742] 3fe0: 40140da4 be8f9b80 0004aefc 40140db8 20000010
be8f9eb8 ffffffff ffffffff
[  665.192860] Backtrace:
[  665.195305] [<c002b9bc>] (__bug+0x0/0x30) from [<c00a4d38>]
(vfs_kern_mount+0x84/0x118)
[  665.203266] [<c00a4cb4>] (vfs_kern_mount+0x0/0x118) from
[<c00a4e28>] (do_kern_mount+0x3c/0xe0)
[  665.211902]  r8:00008000 r7:c689cbc0 r6:c686b000 r5:c689cbe0 r4:c03e5cd8
[  665.218619] [<c00a4dec>] (do_kern_mount+0x0/0xe0) from [<c00be030>]
(do_mount+0x668/0x6ec)
[  665.226822]  r8:00008000 r7:00000000 r6:00000000 r5:c689cbc0 r4:00000020
[  665.233335] r3:c686b000
[  665.235941] [<c00bd9c8>] (do_mount+0x0/0x6ec) from [<c00be140>]
(sys_mount+0x8c/0xcc)
[  665.243751] [<c00be0b4>] (sys_mount+0x0/0xcc) from [<c0027f60>]
(ret_fast_syscall+0x0/0x2c)
[  665.252039]  r7:00000015 r6:4018d380 r5:be8f9c70 r4:000b9018
[  665.257693] Code: e59f0010 e1a01003 eb0b42cf e3a03000 (e5833000)
[  665.264041] ---[ end trace f4c146898e7fbb35 ]---
Segmentation fault
#

If I try mount one more time:

# mount -t ubifs /dev/ubi0_0 /mnt
[  726.910538] UBI DBG (pid 1018): ubi_open_volume_path: open volume
/dev/ubi0_0, mode 1
[  726.918530] UBI DBG (pid 1018): ubi_open_volume: open device 0,
volume 0, mode 1
[  726.925986] UBI DBG (pid 1018): ubi_open_volume: open device 0,
volume 0, mode 2
[  726.952020] UBIFS: read-only UBI device
[  726.955874] UBI DBG (pid 1018): ubi_is_mapped: test LEB 0:0
[  726.961568] UBIFS error (pid 1018): mount_ubifs: cannot mount
read-write - read-only media
[  726.988356] UBI DBG (pid 1018): ubi_close_volume: close device 0,
volume 0, mode 2
[  726.995913] UBI DBG (pid 1018): ubi_close_volume: close device 0,
volume 0, mode 1
[  727.007180] UBI DBG (pid 1018): ubi_open_volume_path: open volume
/dev/ubi0_0, mode 1
[  727.015195] UBI DBG (pid 1018): ubi_open_volume: open device 0,
volume 0, mode 1
[  727.022720] UBI DBG (pid 1018): ubi_open_volume: open device 0,
volume 0, mode 2
[  727.035420] UBIFS: read-only UBI device
[  727.039428] UBI DBG (pid 1018): ubi_is_mapped: test LEB 0:0
[  727.045149] UBI DBG (pid 1018): ubi_leb_read: read 4096 bytes from LEB 0:0:0
[  727.057599] UBI DBG (pid 1018): ubi_leb_read: read 126976 bytes
from LEB 0:1:0
[  727.089040] UBI DBG (pid 1018): ubi_io_read: fixable bit-flip
detected at PEB 3
[  727.096321] UBI DBG (pid 1018): ubi_wl_scrub_peb: schedule PEB 3
for scrubbing
[  727.104738] UBI DBG (pid 1018): ubi_leb_read: read 126976 bytes
from LEB 0:1:0
[  727.138638] UBI DBG (pid 1018): ubi_io_read: fixable bit-flip
detected at PEB 3
[  727.145919] UBI DBG (pid 1018): ubi_wl_scrub_peb: schedule PEB 3
for scrubbing
[  727.155845] UBI DBG (pid 1018): ubi_leb_read: read 126976 bytes
from LEB 0:2:0
[  727.192788] UBIFS: recovered master node from LEB 1
[  727.198194] UBI DBG (pid 1018): ubi_leb_read: read 11 bytes from LEB 0:8:1868
[  727.206483] UBI DBG (pid 1018): ubi_leb_read: read 12 bytes from LEB 0:8:1856
[  727.213789] UBI DBG (pid 1018): ubi_leb_read: read 12 bytes from LEB 0:8:1844
[  727.221136] UBI DBG (pid 1018): ubi_leb_read: read 12 bytes from LEB 0:8:1820
[  727.228335] UBI DBG (pid 1018): ubi_leb_read: read 12 bytes from LEB 0:8:1748
[  727.235442] UBI DBG (pid 1018): ubi_leb_read: read 17 bytes from LEB 0:8:1479
[  727.242813] UBI DBG (pid 1018): ubi_leb_read: read 126976 bytes
from LEB 0:3:0
[  727.285249] UBI DBG (pid 1018): ubi_leb_read: read 126976 bytes
from LEB 0:4:0
[  727.318372] UBI DBG (pid 1018): ubi_leb_read: read 17 bytes from LEB 0:8:1445
[  727.325575] UBIFS: mounted UBI device 0, volume 0, name "rootfs"
[  727.331666] UBIFS: mounted read-only
[  727.335222] UBIFS: file system size:   44441600 bytes (43400 KiB,
42 MiB, 350 LEBs)
[  727.342863] UBIFS: journal size:       9023488 bytes (8812 KiB, 8
MiB, 72 LEBs)
[  727.350154] UBIFS: media format:       w4/r0 (latest is w4/r0)
[  727.355945] UBIFS: default compressor: lzo
[  727.360043] UBIFS: reserved for root:  0 bytes (0 KiB)
[  727.365179] UBI DBG (pid 1018): ubi_leb_read: read 188 bytes from
LEB 0:360:66688
[  727.373887] UBI DBG (pid 1018): ubi_leb_read: read 188 bytes from
LEB 0:360:65256
[  727.386062] UBI DBG (pid 1018): ubi_leb_read: read 188 bytes from
LEB 0:360:53928
[  727.398812] UBI DBG (pid 1018): ubi_leb_read: read 188 bytes from
LEB 0:359:90216
[  727.408316] UBI DBG (pid 1018): ubi_leb_read: read 188 bytes from LEB 0:354:0
[  727.416968] UBI DBG (pid 1018): ubi_leb_read: read 160 bytes from
LEB 0:352:12248
[  727.439783] UBI DBG (pid 1018): ubi_close_volume: close device 0,
volume 0, mode 1
#

It succeeds by using read-only mode. Verification:

# mount | grep ubi
/dev/ubi0_0 on /mnt type ubifs (ro,relatime)


And this is how it looks when /dev/ubi0_0 is created with ubimkvol +
ubiupdatevol (mount succeds, even in rw mode):

# mount -t ubifs /dev/ubi0_0 /mnt/
[ 1977.951135] UBI DBG (pid 1046): ubi_open_volume_path: open volume
/dev/ubi0_0, mode 1
[ 1977.959138] UBI DBG (pid 1046): ubi_open_volume: open device 0,
volume 0, mode 1
[ 1977.966629] UBI DBG (pid 1046): ubi_open_volume: open device 0,
volume 0, mode 2
[ 1977.980317] UBI DBG (pid 1046): ubi_is_mapped: test LEB 0:0
[ 1977.986369] UBI DBG (pid 1046): ubi_leb_read: read 4096 bytes from LEB 0:0:0
[ 1977.996481] UBI DBG (pid 1046): ubi_leb_change: atomically write
4096 bytes to LEB 0:0
[ 1978.166771] UBI DBG (pid 1046): ubi_leb_read: read 126976 bytes
from LEB 0:1:0
[ 1978.276756] UBI DBG (pid 1046): ubi_leb_read: read 126976 bytes
from LEB 0:2:0
[ 1978.386391] UBI DBG (pid 1046): ubi_leb_write: write 2048 bytes to
LEB 0:1:2048
[ 1978.458923] UBI DBG (pid 1046): ubi_leb_write: write 2048 bytes to
LEB 0:2:2048
[ 1978.520369] UBI DBG (pid 1046): ubi_leb_read: read 11 bytes from LEB 0:8:1868
[ 1978.529013] UBI DBG (pid 1046): ubi_leb_unmap: unmap LEB 0:9
[ 1978.534805] UBI DBG (pid 1046): ubi_leb_read: read 12 bytes from LEB 0:8:1856
[ 1978.541955] UBI DBG (pid 1046): ubi_leb_read: read 12 bytes from LEB 0:8:1844
[ 1978.549146] UBI DBG (pid 1046): ubi_leb_read: read 12 bytes from LEB 0:8:1820
[ 1978.556332] UBI DBG (pid 1046): ubi_leb_read: read 12 bytes from LEB 0:8:1748
[ 1978.563441] UBI DBG (pid 1046): ubi_leb_read: read 17 bytes from LEB 0:8:1479
[ 1978.570830] UBI DBG (pid 1046): ubi_leb_read: read 126976 bytes
from LEB 0:3:0
[ 1978.639280] UBI DBG (pid 1046): ubi_leb_read: read 126976 bytes
from LEB 0:4:0
[ 1978.649533] UBI DBG (pid 1046): ubi_leb_unmap: unmap LEB 0:10
[ 1978.655423] UBI DBG (pid 1046): ubi_leb_read: read 17 bytes from LEB 0:8:1445
[ 1978.662589] UBI DBG (pid 1046): ubi_leb_unmap: unmap LEB 0:353
[ 1978.668471] UBIFS: mounted UBI device 0, volume 0, name "rootfs"
[ 1978.674487] UBIFS: file system size:   62472192 bytes (61008 KiB,
59 MiB, 492 LEBs)
[ 1978.682095] UBIFS: journal size:       9023488 bytes (8812 KiB, 8
MiB, 72 LEBs)
[ 1978.689388] UBIFS: media format:       w4/r0 (latest is w4/r0)
[ 1978.695208] UBIFS: default compressor: lzo
[ 1978.699279] UBIFS: reserved for root:  0 bytes (0 KiB)
[ 1978.704447] UBI DBG (pid 1046): ubi_leb_read: read 188 bytes from
LEB 0:360:66688
[ 1978.715500] UBI DBG (pid 1046): ubi_leb_read: read 188 bytes from
LEB 0:360:65256
[ 1978.727822] UBI DBG (pid 1046): ubi_leb_read: read 188 bytes from
LEB 0:360:53928
[ 1978.739949] UBI DBG (pid 1046): ubi_leb_read: read 188 bytes from
LEB 0:359:90216
[ 1978.752414] UBI DBG (pid 1046): ubi_leb_read: read 188 bytes from LEB 0:354:0
[ 1978.764848] UBI DBG (pid 1046): ubi_leb_read: read 160 bytes from
LEB 0:352:12248
[ 1978.774388] UBI DBG (pid 1046): ubi_close_volume: close device 0,
volume 0, mode 1
# mount | grep ubi
/dev/ubi0_0 on /mnt type ubifs (rw,relatime)

I'll get back when I find out more. But of course; any help appreciated :-)

Best regards,
Bjørn Forsman

[1]: http://www.linux-mtd.infradead.org/doc/ubifs.html#L_how_send_bugreport



More information about the linux-mtd mailing list