ubifs error after power-cut

Zhou zhouwarcraft at sina.com
Thu Jul 6 04:26:39 PDT 2017


Hi Artem 

I do the MTD tests

My flash chip is Nor-flash,i just do speed and stress stress

#
#
#
# insmod mtd_stresstest.ko dev=4
[  148.944257]
[  148.945834] =================================================
[  148.951594] mtd_stresstest: MTD device: 4
[  148.956693] mtd_stresstest: not NAND flash, assume page size is 512 bytes.
[  148.963606] mtd_stresstest: MTD device size 10485760, eraseblock size 65536, page size 512, count of eraseblocks 160, pages per eraseblock 128, OOB size 0
[  148.982190] mtd_stresstest: doing operations
[  148.986511] mtd_stresstest: 0 operations done
[  267.492503] mtd_stresstest: 1024 operations done
[  380.597048] mtd_stresstest: 2048 operations done
[  498.965403] mtd_stresstest: 3072 operations done
[  613.959071] mtd_stresstest: 4096 operations done
[  727.582584] mtd_stresstest: 5120 operations done
[  843.713623] mtd_stresstest: 6144 operations done
[  965.796715] mtd_stresstest: 7168 operations done
[ 1083.998768] mtd_stresstest: 8192 operations done
[ 1197.049802] mtd_stresstest: 9216 operations done
[ 1278.214729] mtd_stresstest: finished, 10000 operations done
[ 1278.220812] =================================================
#

# insmod mtd_speedtest.ko dev=4
[ 1360.104141]
[ 1360.105671] =================================================
[ 1360.111465] mtd_speedtest: MTD device: 4
[ 1360.116184] mtd_speedtest: not NAND flash, assume page size is 512 bytes.
[ 1360.123027] mtd_speedtest: MTD device size 10485760, eraseblock size 65536, page size 512, count of eraseblocks 160, pages per eraseblock 128, OOB size 0
[ 1384.841783] mtd_speedtest: testing eraseblock write speed
[ 1396.455062] mtd_speedtest: eraseblock write speed is 882 KiB/s
[ 1396.460934] mtd_speedtest: testing eraseblock read speed
[ 1396.893461] mtd_speedtest: eraseblock read speed is 23981 KiB/s
[ 1421.649779] mtd_speedtest: testing page write speed
[ 1434.075620] mtd_speedtest: page write speed is 824 KiB/s
[ 1434.080961] mtd_speedtest: testing page read speed
[ 1434.602291] mtd_speedtest: page read speed is 19844 KiB/s
[ 1459.405787] mtd_speedtest: testing 2 page write speed
[ 1471.246926] mtd_speedtest: 2 page write speed is 865 KiB/s
[ 1471.252434] mtd_speedtest: testing 2 page read speed
[ 1471.725673] mtd_speedtest: 2 page read speed is 21880 KiB/s
[ 1471.731294] mtd_speedtest: Testing erase speed
[ 1496.521813] mtd_speedtest: erase speed is 413 KiB/s
[ 1496.526725] mtd_speedtest: Testing 2x multi-block erase speed
[ 1521.129789] mtd_speedtest: 2x multi-block erase speed is 416 KiB/s
[ 1521.136005] mtd_speedtest: Testing 4x multi-block erase speed
[ 1545.757781] mtd_speedtest: 4x multi-block erase speed is 415 KiB/s
[ 1545.763983] mtd_speedtest: Testing 8x multi-block erase speed
[ 1570.389788] mtd_speedtest: 8x multi-block erase speed is 415 KiB/s
[ 1570.395995] mtd_speedtest: Testing 16x multi-block erase speed
[ 1594.994377] mtd_speedtest: 16x multi-block erase speed is 416 KiB/s
[ 1595.000670] mtd_speedtest: Testing 32x multi-block erase speed
[ 1619.621789] mtd_speedtest: 32x multi-block erase speed is 416 KiB/s
[ 1619.628082] mtd_speedtest: Testing 64x multi-block erase speed
[ 1644.221800] mtd_speedtest: 64x multi-block erase speed is 416 KiB/s
[ 1644.228087] mtd_speedtest: finished
[ 1644.232147] =================================================

I think the test's result is fine,maybe not hardware issue or mtd issue.

And I found something strange.

First error:I send you before,it caused by mount,indexing node is corrupted

[    2.580988] UBIFS: background thread "ubifs_bgt2_0" started, PID 76
[    2.587396] UBIFS error (pid 75): ubifs_check_node: bad CRC: calculated 0x4463c479, read 0xccafc492
[    2.596418] UBIFS error (pid 75): ubifs_check_node: bad node at LEB 23:22600
[    2.603445]  magic          0x6101831
[    2.607097]  crc            0xccafc492
[    2.610838]  node_type      9 (indexing node)
[    2.615184]  group_type     0 (no node group)
[    2.619528]  sqnum          6557
[    2.622751]  len            48
[    2.625803]  child_cnt      1
[    2.628747]  level          0
[    2.631710]  Branches:
[    2.634076]  0: LEB 11:27936 len 160 key (bad key type: 0xffffffff, 0xffffffff)
[    2.641370] CPU: 0 PID: 75 Comm: mount Not tainted 3.14.19 #1
[    2.647137] [<c0015910>] (unwind_backtrace) from [<c0011ff8>] (show_stack+0x10/0x14)
[    2.654868] [<c0011ff8>] (show_stack) from [<c0475264>] (dump_stack+0x80/0x90)
[    2.662080] [<c0475264>] (dump_stack) from [<c01a5c00>] (ubifs_check_node+0x180/0x298)
[    2.669983] [<c01a5c00>] (ubifs_check_node) from [<c01a7448>] (ubifs_read_node+0xe4/0x2e4)
[    2.678240] [<c01a7448>] (ubifs_read_node) from [<c01b17b0>] (dbg_old_index_check_init+0x64/0xa4)
[    2.687090] [<c01b17b0>] (dbg_old_index_check_init) from [<c01a2a18>] (ubifs_mount+0xe0c/0x1f10)
[    2.695859] [<c01a2a18>] (ubifs_mount) from [<c00a8428>] (mount_fs+0x14/0xcc)
[    2.702991] [<c00a8428>] (mount_fs) from [<c00c04b0>] (vfs_kern_mount+0x48/0x108)
[    2.710463] [<c00c04b0>] (vfs_kern_mount) from [<c00c2dd4>] (do_mount+0x1b8/0xa54)
[    2.718021] [<c00c2dd4>] (do_mount) from [<c00c39d4>] (SyS_mount+0x84/0xb8)
[    2.724978] [<c00c39d4>] (SyS_mount) from [<c000ebe0>] (ret_fast_syscall+0x0/0x30)
[    2.732527] UBIFS error (pid 75): ubifs_read_node: expected node type 9
[    2.739139] UBIFS: background thread "ubifs_bgt2_0" stops
mount: mounting ubi2:sflashfs2 on /data2 failed: Structure needs cleaning

Second error:the NEW one ,it caused by ls,In my mount script,after mounting,i use ls to check my partition.
This time is inode node.

[    1.925846] UBIFS: recovery completed
[    1.929611] UBIFS: mounted UBI device 1, volume 0, name "sflashfs1"
[    1.935864] UBIFS: LEB size: 65408 bytes (63 KiB), min./max. I/O unit sizes: 8 bytes/256 bytes
[    1.944452] UBIFS: FS size: 9549568 bytes (9 MiB, 146 LEBs), journal size 523265 bytes (0 MiB, 7 LEBs)
[    1.953727] UBIFS: reserved for root: 451049 bytes (440 KiB)
[    1.959374] UBIFS: media format: w4/r0 (latest is w4/r0), UUID 0B65F047-B1AB-416C-B509-52608BF5CD50, small LPT model
/data1:
[    2.084260] UBIFS error (pid 60): ubifs_check_node: bad CRC: calculated 0x2603efdc, read 0x6265efa9
[    2.093535] UBIFS error (pid 60): ubifs_check_node: bad node at LEB 11:2200
[    2.100479]  magic          0x6101831
[    2.104139]  crc            0x6265efa9
[    2.107879]  node_type      0 (inode node)
[    2.111965]  group_type     2 (last of node group)
[    2.116742]  sqnum          861
[    2.119878]  len            160
[    2.123016]  key            (68, inode)
[    2.126842]  creat_sqnum    857
[    2.129978]  size           1152310
[    2.133443]  nlink          1
[    2.136407]  atime          33.0
[    2.139629]  mtime          33.0
[    2.142852]  ctime          33.0
[    2.146073]  uid            0
[    2.149021]  gid            0
[    2.151985]  mode           33188
[    2.155293]  flags          0x1
[    2.158429]  xattr_cnt      0
[    2.161377]  xattr_size     0
[    2.164339]  xattr_names    0
[    2.167302]  compr_type     0x1
[    2.170439]  data len       0
[    2.173395] CPU: 0 PID: 60 Comm: ls Not tainted 3.14.19 #1
[    2.178902] [<c0015910>] (unwind_backtrace) from [<c0011ff8>] (show_stack+0x10/0x14)
[    2.186632] [<c0011ff8>] (show_stack) from [<c0475264>] (dump_stack+0x80/0x90)
[    2.193844] [<c0475264>] (dump_stack) from [<c01a5c00>] (ubifs_check_node+0x180/0x298)
[    2.201747] [<c01a5c00>] (ubifs_check_node) from [<c01a7448>] (ubifs_read_node+0xe4/0x2e4)
[    2.209990] [<c01a7448>] (ubifs_read_node) from [<c01c7d14>] (ubifs_tnc_read_node+0x4c/0x1e8)
[    2.218491] [<c01c7d14>] (ubifs_tnc_read_node) from [<c01ab158>] (ubifs_tnc_locate+0x1a4/0x1ac)
[    2.227164] [<c01ab158>] (ubifs_tnc_locate) from [<c01a16ac>] (ubifs_iget+0x98/0x5f8)
[    2.234973] [<c01a16ac>] (ubifs_iget) from [<c019e880>] (ubifs_lookup+0x120/0x244)
[    2.242531] [<c019e880>] (ubifs_lookup) from [<c00ad564>] (lookup_real+0x20/0x4c)
[    2.250003] [<c00ad564>] (lookup_real) from [<c00adeb0>] (__lookup_hash+0x34/0x3c)
[    2.257563] [<c00adeb0>] (__lookup_hash) from [<c00aeab0>] (lookup_slow+0x38/0xa4)
[    2.265119] [<c00aeab0>] (lookup_slow) from [<c00b0638>] (path_lookupat+0x6d8/0x720)
[    2.272844] [<c00b0638>] (path_lookupat) from [<c00b06a0>] (filename_lookup.isra.54+0x20/0x60)
[    2.281431] [<c00b06a0>] (filename_lookup.isra.54) from [<c00b2f2c>] (user_path_at_empty+0x50/0x78)
[    2.290451] [<c00b2f2c>] (user_path_at_empty) from [<c00b2f68>] (user_path_at+0x14/0x1c)
[    2.298521] [<c00b2f68>] (user_path_at) from [<c00a9038>] (vfs_fstatat+0x44/0x98)
[    2.305986] [<c00a9038>] (vfs_fstatat) from [<c00a9748>] (SyS_lstat64+0x14/0x30)
[    2.313366] [<c00a9748>] (SyS_lstat64) from [<c000ebe0>] (ret_fast_syscall+0x0/0x30)
[    2.321083] UBIFS error (pid 60): ubifs_read_node: expected node type 0
[    2.327676] UBIFS error (pid 60): ubifs_iget: failed to read inode 68, error -117
[    2.335171] UBIFS error (pid 60): ubifs_lookup: dead directory entry 'flashNo3', error -117
[    2.343522] UBIFS warning (pid 60): ubifs_ro_mode: switched to read-only mode, error -117
[    2.351684] CPU: 0 PID: 60 Comm: ls Not tainted 3.14.19 #1
[    2.357169] [<c0015910>] (unwind_backtrace) from [<c0011ff8>] (show_stack+0x10/0x14)
[    2.364898] [<c0011ff8>] (show_stack) from [<c0475264>] (dump_stack+0x80/0x90)
[    2.372110] [<c0475264>] (dump_stack) from [<c019e994>] (ubifs_lookup+0x234/0x244)
[    2.379664] [<c019e994>] (ubifs_lookup) from [<c00ad564>] (lookup_real+0x20/0x4c)
[    2.387137] [<c00ad564>] (lookup_real) from [<c00adeb0>] (__lookup_hash+0x34/0x3c)
[    2.394698] [<c00adeb0>] (__lookup_hash) from [<c00aeab0>] (lookup_slow+0x38/0xa4)
[    2.402256] [<c00aeab0>] (lookup_slow) from [<c00b0638>] (path_lookupat+0x6d8/0x720)
[    2.409979] [<c00b0638>] (path_lookupat) from [<c00b06a0>] (filename_lookup.isra.54+0x20/0x60)
[    2.418566] [<c00b06a0>] (filename_lookup.isra.54) from [<c00b2f2c>] (user_path_at_empty+0x50/0x78)
[    2.427586] [<c00b2f2c>] (user_path_at_empty) from [<c00b2f68>] (user_path_at+0x14/0x1c)
[    2.435655] [<c00b2f68>] (user_path_at) from [<c00a9038>] (vfs_fstatat+0x44/0x98)
[    2.443122] [<c00a9038>] (vfs_fstatat) from [<c00a9748>] (SyS_lstat64+0x14/0x30)
[    2.450501] [<c00a9748>] (SyS_lstat64) from [<c000ebe0>] (ret_fast_syscall+0x0/0x30)
ls: /data1/flashNo3: Structure needs cleaning

Like Richard said,maybe something wrong with Nor-flash configuration.

Do you have any suggestion,what should I check next stage.

Best Wishes
Zhou
-----Original Message-----
From: Artem Bityutskiy [mailto:dedekind1 at gmail.com] 
Sent: Thursday, July 06, 2017 2:48 PM
To: Richard Weinberger; zhouwarcraft at sina.com
Cc: linux-mtd
Subject: Re: ubifs error after power-cut


On Tue, 2017-07-04 at 08:56 +0200, Richard Weinberger wrote:
> > what  you think about this problem? Is it a hardware problem?
> 
> It could be a hardware issues, yes. But also a misconfiguration
> of your flash chip.
> Maybe you give your flash not enough time to write data and after a
> power-cut
> already written data corrupts.

Do the MTD tests still work? Makes sense to run them.






More information about the linux-mtd mailing list