* UBIFS Index Node Corruption - Invalid Key Type
@ 2016-05-10 12:14 DHANAPAL, GNANACHANDRAN (G.)
2016-05-10 13:58 ` Richard Weinberger
0 siblings, 1 reply; 15+ messages in thread
From: DHANAPAL, GNANACHANDRAN (G.) @ 2016-05-10 12:14 UTC (permalink / raw)
To: linux-mtd
Cc: Artem Bityutskiy, Adrian Hunter, Babu, Viswanathan (V.),
CN, Aananth (A.A.), Gunasundar, Balamanikandan (B.),
gnanachandran
[-- Attachment #1: Type: text/plain, Size: 2173 bytes --]
Hi There,
We have i.MX6d based platform that has FSL BSP 3.10.17 running.
There is SLC Micron NAND of size 2GB with 512K Block size and 4K min I/O used
for software storage. This NAND has got 7 partitions, Among that two partitions
have Read-Write ubifs file system for runtime data and one has Read-only ubifs
file system that has all the system files. Recently we have observed a issue that
one of RW ubifs partition failed to mount due to invalid key type in one of index
node in ubifs. we have seen the same issue in two units out of 1000 units running
in the field.
Following is the index node that has invalid key in its first branch.
key type = 0xa917dd4c >> 29 = 5 (invalid key)
magic 0x6101831
crc 0x944add59
node_type 9 (indexing node)
group_type 0 (no node group)
sqnum 378678
len 148
child_cnt 6
level 2
Branches:
0: LEB 569:280144 len 108 key (bad key type: 0x000001, 0xa917dd4c)
1: LEB 446:349792 len 108 key (5595, inode)
2: LEB 584:361528 len 108 key (5822, inode)
3: LEB 602:255360 len 108 key (6050, inode)
4: LEB 613:480280 len 188 key (6258, inode)
5: LEB 614:373784 len 88 key (6521, data, 25)
Please help us to understand following points
1. Did this happen because abrupt power cut ? if so, how could CRC of the node still be intact?
2. Could there be any bit flip ? but still again CRC intact.
3. Would the key pointed by corrupted branch be UBIFS_DENT_KEY or UBIFS_XENT_KEY ?
Because 29 bit of key[0] (0xa917dd4c & 0x1FFFFFFF) seems to have some kind of hash value.
but node (at leb 569:280144) that is pointed by corrupted branch seem to be index node.
4. This corrupted entry is always seen in first branch of an index node in two failed units. Could there be reason?
5. Since CRC is intact, would there be any possibility or scenario that corrupted node can be written with valid CRC?
Please share us if you have any suggestions or comments.
Attachement: Debug mount log of this partition.
mtd Partition : /dev/mtd7
ubifs partition name : meta
Cheers
Gnana
[-- Attachment #2: meta-mtd7-mount-log.log --]
[-- Type: text/plain, Size: 41375 bytes --]
/ #
/ # mount -t ubifs /dev/ubi7_0 /meta
UBIFS: background thread "ubifs_bgt7_0" started, PID 188
<7>UBIFS DBG gen (pid 187): name /dev/ubi7_0, flags 0x0
<7>UBI DBG gen (pid 187): open volume /dev/ubi7_0, mode 1
<7>UBI DBG gen (pid 187): open device 7, volume 0, mode 1
<7>UBIFS DBG gen (pid 187): opened ubi7_0
<7>UBI DBG gen (pid 187): open device 7, volume 0, mode 2
<7>UBI DBG gen (pid 187): test LEB 0:0
<7>UBIFS DBG io (pid 187): LEB 0:0, superblock node, length 4096
<7>UBI DBG gen (pid 187): read 4096 bytes from LEB 0:0:0
<7>UBI DBG eba (pid 187): read 4096 bytes from offset 0 of LEB 0:0, PEB 258
<7>UBI DBG io (pid 187): read 4096 bytes from PEB 258:8192
<7>UBIFS DBG scan (pid 187): scan LEB 1:0
<7>UBI DBG gen (pid 187): read 516096 bytes from LEB 0:1:0
<7>UBI DBG eba (pid 187): read 516096 bytes from offset 0 of LEB 0:1, PEB 569
<7>UBI DBG io (pid 187): read 516096 bytes from PEB 569:8192
<5>UBIFS: background thread "ubifs_bgt7_0" started, PID 188
<7>UBIFS DBG scan (pid 187): look at LEB 1:0 (516096 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:0
<7>UBIFS DBG scan (pid 187): look at LEB 1:512 (515584 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:512
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:512, offset now 4096
<7>UBIFS DBG scan (pid 187): look at LEB 1:4096 (512000 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:4096
<7>UBIFS DBG scan (pid 187): look at LEB 1:4608 (511488 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:4608
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:4608, offset now 8192
<7>UBIFS DBG scan (pid 187): look at LEB 1:8192 (507904 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:8192
<7>UBIFS DBG scan (pid 187): look at LEB 1:8704 (507392 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:8704
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:8704, offset now 12288
<7>UBIFS DBG scan (pid 187): look at LEB 1:12288 (503808 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:12288
<7>UBIFS DBG UBIFS: recovery needed
scan (pid 187): look at LEB 1:12800 (503296 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:12800
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:12800, offset now 16384
<7>UBIFS DBG scan (pid 187): look at LEB 1:16384 (499712 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:16384
<7>UBIFS DBG scan (pid 187): look at LEB 1:16896 (499200 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:16896
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:16896, offset now 20480
<7>UBIFS DBG scan (pid 187): look at LEB 1:20480 (495616 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:20480
<7>UBIFS DBG scan (pid 187): look at LEB 1:20992 (495104 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:20992
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:20992, offset now 24576
<7>UBIFS DBG scan (pid 187): look at LEB 1:24576 (491520 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:24576
<7>UBIFS DBG scan (pid 187): look at LEB 1:25088 (491008 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:25088
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:25088, offset now 28672
<7>UBIFS DBG scan (pid 187): look at LEB 1:28672 (487424 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:28672
<7>UBIFS DBG scan (pid 187): look at LEB 1:29184 (486912 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:29184
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:29184, offset now 32768
<7>UBIFS DBG scan (pid 187): look at LEB 1:32768 (483328 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:32768
<7>UBIFS DBG scan (pid 187): look at LEB 1:33280 (482816 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:33280
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:33280, offset now 36864
<7>UBIFS DBG scan (pid 187): look at LEB 1:36864 (479232 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:36864
<7>UBIFS DBG scan (pid 187): look at LEB 1:37376 (478720 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:37376
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:37376, offset now 40960
<7>UBIFS DBG scan (pid 187): look at LEB 1:40960 (475136 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:40960
<7>UBIFS DBG scan (pid 187): look at LEB 1:41472 (474624 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:41472
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:41472, offset now 45056
<7>UBIFS DBG scan (pid 187): look at LEB 1:45056 (471040 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:45056
<7>UBIFS DBG scan (pid 187): look at LEB 1:45568 (470528 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:45568
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:45568, offset now 49152
<7>UBIFS DBG scan (pid 187): look at LEB 1:49152 (466944 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:49152
<7>UBIFS DBG scan (pid 187): look at LEB 1:49664 (466432 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:49664
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:49664, offset now 53248
<7>UBIFS DBG scan (pid 187): look at LEB 1:53248 (462848 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:53248
<7>UBIFS DBG scan (pid 187): look at LEB 1:53760 (462336 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:53760
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:53760, offset now 57344
<7>UBIFS DBG scan (pid 187): look at LEB 1:57344 (458752 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:57344
<7>UBIFS DBG scan (pid 1UBIFS error (pid 187): read_znode: bad key type at slot 0: 5
87): look at LEB 1:57856 (458240 UBIFS error (pid 187): read_znode: bad indexing node at LEB 614:373872, error 3
bytes left)
<7>UBIFS DBG scan (p magic 0x6101831
id 187): scanning padding node at crc 0x944add59
LEB 1:57856
<7>UBIFS DBG scan ( node_type 9 (indexing node)
pid 187): 3556 bytes padded at LE group_type 0 (no node group)
B 1:57856, offset now 61440
<7>U sqnum 378678
BIFS DBG scan (pid 187): look at len 148
LEB 1:61440 (454656 bytes left)
child_cnt 6
<7>UBIFS DBG scan (pid 187): scan level 2
ning master node at LEB 1:61440
Branches:
<7>UBIFS DBG scan (pid 187): look 0: LEB 569:280144 len 108 key (bad key type: 0x000001, 0xa917dd4c)
at LEB 1:61952 (454144 bytes lef 1: LEB 446:349792 len 108 key (5595, inode)
t)
<7>UBIFS DBG scan (pid 187): 2: LEB 584:361528 len 108 key (5822, inode)
scanning padding node at LEB 1:61 3: LEB 602:255360 len 108 key (6050, inode)
952
<7>UBIFS DBG scan (pid 187): 4: LEB 613:480280 len 188 key (6258, inode)
3556 bytes padded at LEB 1:61952 5: LEB 614:373784 len 88 key (6521, data, 25)
, offset now 65536
<7>UBIFS DBG UBIFS: background thread "ubifs_bgt7_0" stops
scan (pid 187): look at LEB 1:65536 (450560 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:65536
<7>UBIFS DBG scan (pid 187): look at LEB 1:66048 (450048 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:66048
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:66048, offset now 69632
<7>UBIFS DBG scan (pid 187): look at LEB 1:69632 (446464 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:69632
<7>UBIFS DBG scan (pid 187): look at LEB 1:70144 (445952 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:70144
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:70144, offset now 73728
<7>UBIFS DBG scan (pid 187): look at LEB 1:73728 (442368 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:73728
<7>UBIFS DBG scan (pid 187): look at LEB 1:74240 (441856 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:74240
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:74240, offset now 77824
<7>UBIFS DBG scan (pid 187): look at LEB 1:77824 (438272 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:77824
<7>UBIFS DBG scan (pid 187): look at LEB 1:78336 (437760 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:78336
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:78336, offset now 81920
<7>UBIFS DBG scan (pid 187): look at LEB 1:81920 (434176 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:81920
<7>UBIFS DBG scan (pid 187): look at LEB 1:82432 (433664 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:82432
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:82432, offset now 86016
<7>UBIFS DBG scan (pid 187): look at LEB 1:86016 (430080 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:86016
<7>UBIFS DBG scan (pid 187): look at LEB 1:86528 (429568 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:86528
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:86528, offset now 90112
<7>UBIFS DBG scan (pid 187): look at LEB 1:90112 (425984 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:90112
<7>UBIFS DBG scan (pid 187): look at LEB 1:90624 (425472 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:90624
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:90624, offset now 94208
<7>UBIFS DBG scan (pid 187): look at LEB 1:94208 (421888 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:94208
<7>UBIFS DBG scan (pid 187): look at LEB 1:94720 (421376 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:94720
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:94720, offset now 98304
<7>UBIFS DBG scan (pid 187): look at LEB 1:98304 (417792 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 1:98304
<7>UBIFS DBG scan (pid 187): look at LEB 1:98816 (417280 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 1:98816
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 1:98816, offset now 102400
<7>UBIFS DBG scan (pid 187): look at LEB 1:102400 (413696 bytes left)
<7>UBIFS DBG scan (pid 187): hit empty space at LEB 1:102400
<7>UBIFS DBG scan (pid 187): stop scanning LEB 1 at offset 102400
<7>UBIFS DBG scan (pid 187): scan LEB 2:0
<7>UBI DBG gen (pid 187): read 516096 bytes from LEB 0:2:0
<7>UBI DBG eba (pid 187): read 516096 bytes from offset 0 of LEB 0:2, PEB 573
<7>UBI DBG io (pid 187): read 516096 bytes from PEB 573:8192
<7>UBIFS DBG scan (pid 187): look at LEB 2:0 (516096 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:0
<7>UBIFS DBG scan (pid 187): look at LEB 2:512 (515584 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:512
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:512, offset now 4096
<7>UBIFS DBG scan (pid 187): look at LEB 2:4096 (512000 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:4096
<7>UBIFS DBG scan (pid 187): look at LEB 2:4608 (511488 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:4608
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:4608, offset now 8192
<7>UBIFS DBG scan (pid 187): look at LEB 2:8192 (507904 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:8192
<7>UBIFS DBG scan (pid 187): look at LEB 2:8704 (507392 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:8704
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:8704, offset now 12288
<7>UBIFS DBG scan (pid 187): look at LEB 2:12288 (503808 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:12288
<7>UBIFS DBG scan (pid 187): look at LEB 2:12800 (503296 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:12800
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:12800, offset now 16384
<7>UBIFS DBG scan (pid 187): look at LEB 2:16384 (499712 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:16384
<7>UBIFS DBG scan (pid 187): look at LEB 2:16896 (499200 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:16896
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:16896, offset now 20480
<7>UBIFS DBG scan (pid 187): look at LEB 2:20480 (495616 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:20480
<7>UBIFS DBG scan (pid 187): look at LEB 2:20992 (495104 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:20992
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:20992, offset now 24576
<7>UBIFS DBG scan (pid 187): look at LEB 2:24576 (491520 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:24576
<7>UBIFS DBG scan (pid 187): look at LEB 2:25088 (491008 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:25088
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:25088, offset now 28672
<7>UBIFS DBG scan (pid 187): look at LEB 2:28672 (487424 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:28672
<7>UBIFS DBG scan (pid 187): look at LEB 2:29184 (486912 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:29184
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:29184, offset now 32768
<7>UBIFS DBG scan (pid 187): look at LEB 2:32768 (483328 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:32768
<7>UBIFS DBG scan (pid 187): look at LEB 2:33280 (482816 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:33280
/ # <7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:33280, offset now 36864
<7>UBIFS DBG scan (pid 187): look at LEB 2:36864 (479232 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:36864
<7>UBIFS DBG scan (pid 187): look at LEB 2:37376 (478720 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:37376
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:37376, offset now 40960
<7>UBIFS DBG scan (pid 187): look at LEB 2:40960 (475136 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:40960
<7>UBIFS DBG scan (pid 187): look at LEB 2:41472 (474624 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:41472
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:41472, offset now 45056
<7>UBIFS DBG scan (pid 187): look at LEB 2:45056 (471040 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:45056
<7>UBIFS DBG scan (pid 187): look at LEB 2:45568 (470528 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:45568
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:45568, offset now 49152
<7>UBIFS DBG scan (pid 187): look at LEB 2:49152 (466944 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:49152
<7>UBIFS DBG scan (pid 187): look at LEB 2:49664 (466432 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:49664
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:49664, offset now 53248
<7>UBIFS DBG scan (pid 187): look at LEB 2:53248 (462848 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:53248
<7>UBIFS DBG scan (pid 187): look at LEB 2:53760 (462336 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:53760
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:53760, offset now 57344
<7>UBIFS DBG scan (pid 187): look at LEB 2:57344 (458752 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:57344
<7>UBIFS DBG scan (pid 187): look at LEB 2:57856 (458240 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:57856
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:57856, offset now 61440
<7>UBIFS DBG scan (pid 187): look at LEB 2:61440 (454656 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:61440
<7>UBIFS DBG scan (pid 187): look at LEB 2:61952 (454144 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:61952
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:61952, offset now 65536
<7>UBIFS DBG scan (pid 187): look at LEB 2:65536 (450560 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:65536
<7>UBIFS DBG scan (pid 187): look at LEB 2:66048 (450048 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:66048
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:66048, offset now 69632
<7>UBIFS DBG scan (pid 187): look at LEB 2:69632 (446464 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:69632
<7>UBIFS DBG scan (pid 187): look at LEB 2:70144 (445952 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:70144
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:70144, offset now 73728
<7>UBIFS DBG scan (pid 187): look at LEB 2:73728 (442368 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:73728
<7>UBIFS DBG scan (pid 187): look at LEB 2:74240 (441856 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:74240
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:74240, offset now 77824
<7>UBIFS DBG scan (pid 187): look at LEB 2:77824 (438272 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:77824
<7>UBIFS DBG scan (pid 187): look at LEB 2:78336 (437760 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:78336
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:78336, offset now 81920
<7>UBIFS DBG scan (pid 187): look at LEB 2:81920 (434176 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:81920
<7>UBIFS DBG scan (pid 187): look at LEB 2:82432 (433664 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:82432
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:82432, offset now 86016
<7>UBIFS DBG scan (pid 187): look at LEB 2:86016 (430080 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:86016
<7>UBIFS DBG scan (pid 187): look at LEB 2:86528 (429568 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:86528
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:86528, offset now 90112
<7>UBIFS DBG scan (pid 187): look at LEB 2:90112 (425984 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:90112
<7>UBIFS DBG scan (pid 187): look at LEB 2:90624 (425472 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:90624
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:90624, offset now 94208
<7>UBIFS DBG scan (pid 187): look at LEB 2:94208 (421888 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:94208
<7>UBIFS DBG scan (pid 187): look at LEB 2:94720 (421376 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:94720
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:94720, offset now 98304
<7>UBIFS DBG scan (pid 187): look at LEB 2:98304 (417792 bytes left)
<7>UBIFS DBG scan (pid 187): scanning master node at LEB 2:98304
<7>UBIFS DBG scan (pid 187): look at LEB 2:98816 (417280 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 2:98816
<7>UBIFS DBG scan (pid 187): 3556 bytes padded at LEB 2:98816, offset now 102400
<7>UBIFS DBG scan (pid 187): look at LEB 2:102400 (413696 bytes left)
<7>UBIFS DBG scan (pid 187): hit empty space at LEB 2:102400
<7>UBIFS DBG scan (pid 187): stop scanning LEB 2 at offset 102400
<7>UBIFS DBG io (pid 187): LEB 614:381600, indexing node, length 68
<7>UBI DBG gen (pid 187): read 68 bytes from LEB 0:614:381600
<7>UBI DBG eba (pid 187): read 68 bytes from offset 381600 of LEB 0:614, PEB 973
<7>UBI DBG io (pid 187): read 68 bytes from PEB 973:389792
<5>UBIFS: recovery needed
<7>UBIFS DBG rcvry (pid 187): checking index head at 614:385024
<7>UBI DBG gen (pid 187): read 4096 bytes from LEB 0:614:385024
<7>UBI DBG eba (pid 187): read 4096 bytes from offset 385024 of LEB 0:614, PEB 973
<7>UBI DBG io (pid 187): read 4096 bytes from PEB 973:393216
<7>UBIFS DBG rcvry (pid 187): checking LPT head at 6:495616
<7>UBI DBG gen (pid 187): read 4096 bytes from LEB 0:6:495616
<7>UBI DBG eba (pid 187): read 4096 bytes from offset 495616 of LEB 0:6, PEB 964
<7>UBI DBG io (pid 187): read 4096 bytes from PEB 964:503808
<7>UBI DBG gen (pid 187): read 12 bytes from LEB 0:6:491520
<7>UBI DBG eba (pid 187): read 12 bytes from offset 491520 of LEB 0:6, PEB 964
<7>UBI DBG io (pid 187): read 12 bytes from PEB 964:499712
<7>UBIFS DBG lp (pid 187): space_bits 16
<7>UBIFS DBG lp (pid 187): lpt_lnum_bits 2
<7>UBIFS DBG lp (pid 187): lpt_offs_bits 19
<7>UBIFS DBG lp (pid 187): lpt_spc_bits 19
<7>UBIFS DBG lp (pid 187): pcnt_bits 8
<7>UBIFS DBG lp (pid 187): lnum_bits 10
<7>UBIFS DBG lp (pid 187): pnode_sz 19
<7>UBIFS DBG lp (pid 187): nnode_sz 13
<7>UBIFS DBG lp (pid 187): ltab_sz 12
<7>UBIFS DBG lp (pid 187): lsave_sz 323
<7>UBIFS DBG lp (pid 187): lsave_cnt 256
<7>UBIFS DBG lp (pid 187): lpt_hght 4
<7>UBIFS DBG lp (pid 187): big_lpt 0
<7>UBIFS DBG lp (pid 187): LPT root is at 6:491622
<7>UBIFS DBG lp (pid 187): LPT head is at 6:495616
<7>UBIFS DBG lp (pid 187): LPT ltab is at 6:491520
<7>UBIFS DBG io (pid 187): LEB 1:102400, master node, length 512 (aligned 4096)
<7>UBI DBG gen (pid 187): write 4096 bytes to LEB 0:1:102400
<7>UBI DBG eba (pid 187): write 4096 bytes at offset 102400 of LEB 0:1, PEB 569
<7>UBI DBG io (pid 187): write 4096 bytes to PEB 569:110592
<7>UBIFS DBG io (pid 187): LEB 2:102400, master node, length 512 (aligned 4096)
<7>UBI DBG gen (pid 187): write 4096 bytes to LEB 0:2:102400
<7>UBI DBG eba (pid 187): write 4096 bytes at offset 102400 of LEB 0:2, PEB 573
<7>UBI DBG io (pid 187): write 4096 bytes to PEB 573:110592
<7>UBI DBG gen (pid 187): read 13 bytes from LEB 0:6:491622
<7>UBI DBG eba (pid 187): read 13 bytes from offset 491622 of LEB 0:6, PEB 964
<7>UBI DBG io (pid 187): read 13 bytes from PEB 964:499814
<7>UBIFS DBG lp (pid 187): LEB 6 add 13 to 495047
<7>UBIFS DBG lp (pid 187): LEB 6 add 12 to 495060
<7>UBI DBG gen (pid 187): read 13 bytes from LEB 0:6:491609
<7>UBI DBG eba (pid 187): read 13 bytes from offset 491609 of LEB 0:6, PEB 964
<7>UBI DBG io (pid 187): read 13 bytes from PEB 964:499801
<7>UBIFS DBG lp (pid 187): LEB 6 add 13 to 495072
<7>UBI DBG gen (pid 187): read 13 bytes from LEB 0:6:491596
<7>UBI DBG eba (pid 187): read 13 bytes from offset 491596 of LEB 0:6, PEB 964
<7>UBI DBG io (pid 187): read 13 bytes from PEB 964:499788
<7>UBIFS DBG lp (pid 187): LEB 6 add 13 to 495085
<7>UBI DBG gen (pid 187): read 13 bytes from LEB 0:6:491583
<7>UBI DBG eba (pid 187): read 13 bytes from offset 491583 of LEB 0:6, PEB 964
<7>UBI DBG io (pid 187): read 13 bytes from PEB 964:499775
<7>UBIFS DBG lp (pid 187): LEB 6 add 13 to 495098
<7>UBI DBG gen (pid 187): read 19 bytes from LEB 0:6:491564
<7>UBI DBG eba (pid 187): read 19 bytes from offset 491564 of LEB 0:6, PEB 964
<7>UBI DBG io (pid 187): read 19 bytes from PEB 964:499756
<7>UBIFS DBG lp (pid 187): LEB 6 add 19 to 495111
<7>UBIFS DBG lp (pid 187): LEB 614, free 131072, dirty 374120, flags 34
<7>UBIFS DBG lp (pid 187): LEB 614, free -2147483647, dirty -2147483647, flags 50
<7>UBIFS DBG lp (pid 187): LEB 614, free 131072, dirty 374120, flags 34
<7>UBIFS DBG mnt (pid 187): start replaying the journal
<7>UBIFS DBG mnt (pid 187): replay log LEB 4:0
<7>UBIFS DBG scan (pid 187): scan LEB 4:0
<7>UBI DBG gen (pid 187): read 516096 bytes from LEB 0:4:0
<7>UBI DBG eba (pid 187): read 516096 bytes from offset 0 of LEB 0:4, PEB 117
<7>UBI DBG io (pid 187): read 516096 bytes from PEB 117:8192
<7>UBIFS DBG scan (pid 187): look at LEB 4:0 (516096 bytes left)
<7>UBIFS DBG scan (pid 187): scanning commit start node at LEB 4:0
<7>UBIFS DBG scan (pid 187): look at LEB 4:32 (516064 bytes left)
<7>UBIFS DBG scan (pid 187): scanning reference node at LEB 4:32
<7>UBIFS DBG scan (pid 187): look at LEB 4:96 (516000 bytes left)
<7>UBIFS DBG scan (pid 187): scanning reference node at LEB 4:96
<7>UBIFS DBG scan (pid 187): look at LEB 4:160 (515936 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 4:160
<7>UBIFS DBG scan (pid 187): 3908 bytes padded at LEB 4:160, offset now 4096
<7>UBIFS DBG scan (pid 187): look at LEB 4:4096 (512000 bytes left)
<7>UBIFS DBG scan (pid 187): hit empty space at LEB 4:4096
<7>UBIFS DBG scan (pid 187): stop scanning LEB 4 at offset 4096
<7>UBIFS DBG mnt (pid 187): commit start sqnum 378712
<7>UBIFS DBG mnt (pid 187): add replay bud LEB 615:413696, head 1
<7>UBIFS DBG log (pid 187): LEB 615:413696, jhead 1 (base), bud_bytes 102400
<7>UBIFS DBG mnt (pid 187): add replay bud LEB 617:167936, head 2
<7>UBIFS DBG log (pid 187): LEB 617:167936, jhead 2 (data), bud_bytes 450560
<7>UBIFS DBG mnt (pid 187): replay log LEB 5:0
<7>UBIFS DBG scan (pid 187): scan LEB 5:0
<7>UBI DBG gen (pid 187): read 516096 bytes from LEB 0:5:0
<7>UBI DBG eba (pid 187): read 516096 bytes from offset 0 of LEB 0:5 (unmapped)
<7>UBIFS DBG scan (pid 187): look at LEB 5:0 (516096 bytes left)
<7>UBIFS DBG scan (pid 187): hit empty space at LEB 5:0
<7>UBIFS DBG scan (pid 187): stop scanning LEB 5 at offset 0
<7>UBIFS DBG mnt (pid 187): replay bud LEB 615, head 1, offs 413696, is_last 1
<7>UBIFS DBG rcvry (pid 187): 615:413696, jhead 1, grouped 1
<7>UBIFS DBG scan (pid 187): scan LEB 615:413696
<7>UBI DBG gen (pid 187): read 102400 bytes from LEB 0:615:413696
<7>UBI DBG eba (pid 187): read 102400 bytes from offset 413696 of LEB 0:615, PEB 690
<7>UBI DBG io (pid 187): read 102400 bytes from PEB 690:421888
<7>UBIFS DBG scan (pid 187): look at LEB 615:413696 (102400 bytes left)
<7>UBIFS DBG scan (pid 187): scanning inode node at LEB 615:413696
<7>UBIFS DBG scan (pid 187): look at LEB 615:413856 (102240 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 615:413856
<7>UBIFS DBG scan (pid 187): 3908 bytes padded at LEB 615:413856, offset now 417792
<7>UBIFS DBG scan (pid 187): look at LEB 615:417792 (98304 bytes left)
<7>UBIFS DBG scan (pid 187): scanning inode node at LEB 615:417792
<7>UBIFS DBG scan (pid 187): look at LEB 615:417952 (98144 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 615:417952
<7>UBIFS DBG scan (pid 187): 3908 bytes padded at LEB 615:417952, offset now 421888
<7>UBIFS DBG scan (pid 187): look at LEB 615:421888 (94208 bytes left)
<7>UBIFS DBG scan (pid 187): scanning direntry node at LEB 615:421888
<7>UBIFS DBG scan (pid 187): look at LEB 615:421992 (94104 bytes left)
<7>UBIFS DBG scan (pid 187): scanning inode node at LEB 615:421992
<7>UBIFS DBG scan (pid 187): look at LEB 615:422176 (93920 bytes left)
<7>UBIFS DBG scan (pid 187): scanning inode node at LEB 615:422176
<7>UBIFS DBG scan (pid 187): look at LEB 615:422336 (93760 bytes left)
<7>UBIFS DBG scan (pid 187): scanning padding node at LEB 615:422336
<7>UBIFS DBG scan (pid 187): 3620 bytes padded at LEB 615:422336, offset now 425984
<7>UBIFS DBG scan (pid 187): look at LEB 615:425984 (90112 bytes left)
<7>UBIFS DBG scan (pid 187): hit empty space at LEB 615:425984
<7>UBIFS DBG rcvry (pid 187): found corruption (-1) at 615:425984
<7>UBIFS DBG rcvry (pid 187): cleaning corruption at 615:425984
<7>UBIFS DBG scan (pid 187): stop scanning LEB 615 at offset 425984
<7>UBIFS DBG rcvry (pid 187): fixing LEB 615 start 413696 endpt 425984
<7>UBI DBG gen (pid 187): read 413696 bytes from LEB 0:615:0
<7>UBI DBG eba (pid 187): read 413696 bytes from offset 0 of LEB 0:615, PEB 690
<7>UBI DBG io (pid 187): read 413696 bytes from PEB 690:8192
<7>UBI DBG gen (pid 187): atomically write 425984 bytes to LEB 0:615
<7>UBI DBG wl (pid 187): added PEB 694 EC 55 to the protection queue
<7>UBI DBG eba (pid 187): change LEB 0:615, PEB 690, write VID hdr to PEB 694
<7>UBI DBG io (pid 187): write VID header to PEB 694
<7>UBI DBG io (pid 187): write 4096 bytes to PEB 694:4096
<7>UBI DBG io (pid 187): write 425984 bytes to PEB 694:8192
<7>UBI DBG wl (pid 187): PEB 690
<7>UBI DBG wl (pid 187): deleted PEB 690 from the protection queue
<7>UBI DBG wl (pid 187): schedule erasure of PEB 690, EC 55, torture 0
<7>UBI DBG wl (pid 174): erase PEB 690 EC 55 LEB 0:615
<7>UBI DBG wl (pid 174): erase PEB 690, old EC 55
<7>UBI DBG io (pid 174): erase PEB 690
<7>UBI DBG wl (pid 174): erased PEB 690, new EC 56
<7>UBI DBG io (pid 174): write EC header to PEB 690
<7>UBI DBG io (pid 174): write 4096 bytes to PEB 690:0
<7>UBIFS DBG mnt (pid 187): add LEB 615:413696, key (68, inode)
<7>UBIFS DBG mnt (pid 187): add LEB 615:417792, key (68, inode)
<7>UBIFS DBG mnt (pid 187): add LEB 615:421888, key (68, direntry, 0x177c167)
<7>UBIFS DBG mnt (pid 187): add LEB 615:421992, key (6568, inode)
<7>UBIFS DBG mnt (pid 187): add LEB 615:422176, key (68, inode)
<7>UBIFS DBG mnt (pid 187): bud LEB 615 replied: dirty 11520, free 90112
<7>UBIFS DBG mnt (pid 187): replay bud LEB 617, head 2, offs 167936, is_last 1
<7>UBIFS DBG rcvry (pid 187): 617:167936, jhead 2, grouped 1
<7>UBIFS DBG scan (pid 187): scan LEB 617:167936
<7>UBI DBG gen (pid 187): read 348160 bytes from LEB 0:617:167936
<7>UBI DBG eba (pid 187): read 348160 bytes from offset 167936 of LEB 0:617, PEB 692
<7>UBI DBG io (pid 187): read 348160 bytes from PEB 692:176128
<7>UBIFS DBG scan (pid 187): look at LEB 617:167936 (348160 bytes left)
<7>UBIFS DBG scan (pid 187): hit empty space at LEB 617:167936
<7>UBIFS DBG rcvry (pid 187): found corruption (-1) at 617:167936
<7>UBIFS DBG rcvry (pid 187): cleaning corruption at 617:167936
<7>UBIFS DBG scan (pid 187): stop scanning LEB 617 at offset 167936
<7>UBIFS DBG rcvry (pid 187): fixing LEB 617 start 167936 endpt 167936
<7>UBI DBG gen (pid 187): read 167936 bytes from LEB 0:617:0
<7>UBI DBG eba (pid 187): read 167936 bytes from offset 0 of LEB 0:617, PEB 692
<7>UBI DBG io (pid 187): read 167936 bytes from PEB 692:8192
<7>UBI DBG gen (pid 187): atomically write 167936 bytes to LEB 0:617
<7>UBI DBG wl (pid 187): added PEB 695 EC 55 to the protection queue
<7>UBI DBG eba (pid 187): change LEB 0:617, PEB 692, write VID hdr to PEB 695
<7>UBI DBG io (pid 187): write VID header to PEB 695
<7>UBI DBG io (pid 187): write 4096 bytes to PEB 695:4096
<7>UBI DBG io (pid 187): write 167936 bytes to PEB 695:8192
<7>UBI DBG wl (pid 187): PEB 692
<7>UBI DBG wl (pid 187): deleted PEB 692 from the protection queue
<7>UBI DBG wl (pid 187): schedule erasure of PEB 692, EC 55, torture 0
<7>UBI DBG wl (pid 174): erase PEB 692 EC 55 LEB 0:617
<7>UBI DBG wl (pid 174): erase PEB 692, old EC 55
<7>UBI DBG io (pid 174): erase PEB 692
<7>UBIFS DBG mnt (pid 187): bud LEB 617 replied: dirty 0, free 348160
<7>UBI DBG wl (pid 174): erased PEB 692, new EC 56
<7>UBI DBG io (pid 174): write EC header to PEB 692
<7>UBI DBG io (pid 174): write 4096 bytes to PEB 692:0
<7>UBIFS DBG mnt (pid 187): LEB 615:413696 len 160 deletion 0 sqnum 378717 key (68, inode)
<7>UBIFS DBG tnc (pid 187): 615:413696, len 160, key (68, inode)
<7>UBIFS DBG tnc (pid 187): search and dirty key (68, inode)
<7>UBIFS DBG io (pid 187): LEB 614:381600, indexing node, length 68
<7>UBI DBG gen (pid 187): read 68 bytes from LEB 0:614:381600
<7>UBI DBG eba (pid 187): read 68 bytes from offset 381600 of LEB 0:614, PEB 973
<7>UBI DBG io (pid 187): read 68 bytes from PEB 973:389792
<7>UBIFS DBG tnc (pid 187): LEB 614:381600, level 5, 2 branch
<7>UBIFS DBG lp (pid 187): LEB 614, free 131072, dirty 374120, flags 48
<7>UBIFS DBG lp (pid 187): LEB 614, free -2147483647, dirty 374188, flags 48
<7>UBIFS DBG lp (pid 187): LEB 614, free 131072, dirty 374120, flags 48
<7>UBIFS DBG io (pid 187): LEB 614:381488, indexing node, length 108
<7>UBI DBG gen (pid 187): read 108 bytes from LEB 0:614:381488
<7>UBI DBG eba (pid 187): read 108 bytes from offset 381488 of LEB 0:614, PEB 973
<7>UBI DBG io (pid 187): read 108 bytes from PEB 973:389680
<7>UBIFS DBG tnc (pid 187): LEB 614:381488, level 4, 4 branch
<7>UBIFS DBG lp (pid 187): LEB 614, free 131072, dirty 374192, flags 48
<7>UBIFS DBG lp (pid 187): LEB 614, free -2147483647, dirty 374300, flags 48
<7>UBIFS DBG lp (pid 187): LEB 614, free 131072, dirty 374192, flags 48
<7>UBIFS DBG io (pid 187): LEB 614:381336, indexing node, length 148
<7>UBI DBG gen (pid 187): read 148 bytes from LEB 0:614:381336
<7>UBI DBG eba (pid 187): read 148 bytes from offset 381336 of LEB 0:614, PEB 973
<7>UBI DBG io (pid 187): read 148 bytes from PEB 973:389528
<7>UBIFS DBG tnc (pid 187): LEB 614:381336, level 3, 6 branch
<7>UBIFS DBG lp (pid 187): LEB 614, free 131072, dirty 374304, flags 48
<7>UBIFS DBG lp (pid 187): LEB 614, free -2147483647, dirty 374452, flags 48
<7>UBIFS DBG lp (pid 187): LEB 614, free 131072, dirty 374304, flags 48
<7>UBIFS DBG io (pid 187): LEB 614:381208, indexing node, length 128
<7>UBI DBG gen (pid 187): read 128 bytes from LEB 0:614:381208
<7>UBI DBG eba (pid 187): read 128 bytes from offset 381208 of LEB 0:614, PEB 973
<7>UBI DBG io (pid 187): read 128 bytes from PEB 973:389400
<7>UBIFS DBG tnc (pid 187): LEB 614:381208, level 2, 5 branch
<7>UBIFS DBG lp (pid 187): LEB 614, free 131072, dirty 374456, flags 48
<7>UBIFS DBG lp (pid 187): LEB 614, free -2147483647, dirty 374584, flags 48
<7>UBIFS DBG lp (pid 187): LEB 614, free 131072, dirty 374456, flags 48
<7>UBIFS DBG io (pid 187): LEB 614:381040, indexing node, length 168
<7>UBI DBG gen (pid 187): read 168 bytes from LEB 0:614:381040
<7>UBI DBG eba (pid 187): read 168 bytes from offset 381040 of LEB 0:614, PEB 973
<7>UBI DBG io (pid 187): read 168 bytes from PEB 973:389232
<7>UBIFS DBG tnc (pid 187): LEB 614:381040, level 1, 7 branch
<7>UBIFS DBG lp (pid 187): LEB 614, free 131072, dirty 374584, flags 48
<7>UBIFS DBG lp (pid 187): LEB 614, free -2147483647, dirty 374752, flags 48
<7>UBIFS DBG lp (pid 187): LEB 614, free 131072, dirty 374584, flags 48
<7>UBIFS DBG io (pid 187): LEB 614:380928, indexing node, length 108
<7>UBI DBG gen (pid 187): read 108 bytes from LEB 0:614:380928
<7>UBI DBG eba (pid 187): read 108 bytes from offset 380928 of LEB 0:614, PEB 973
<7>UBI DBG io (pid 187): read 108 bytes from PEB 973:389120
<7>UBIFS DBG tnc (pid 187): LEB 614:380928, level 0, 4 branch
<7>UBIFS DBG lp (pid 187): LEB 614, free 131072, dirty 374752, flags 48
<7>UBIFS DBG lp (pid 187): LEB 614, free -2147483647, dirty 374860, flags 48
<7>UBIFS DBG lp (pid 187): LEB 614, free 131072, dirty 374752, flags 48
<7>UBIFS DBG tnc (pid 187): found 1, lvl 0, n 0
<7>UBIFS DBG lp (pid 187): LEB 615, free 102400, dirty 411416, flags 1
<7>UBIFS DBG lp (pid 187): LEB 615, free -2147483647, dirty 411576, flags 1
<7>UBIFS DBG lp (pid 187): LEB 615, free 102400, dirty 411416, flags 1
<7>UBIFS DBG mnt (pid 187): LEB 615:417792 len 160 deletion 0 sqnum 378718 key (68, inode)
<7>UBIFS DBG tnc (pid 187): 615:417792, len 160, key (68, inode)
<7>UBIFS DBG tnc (pid 187): search and dirty key (68, inode)
<7>UBIFS DBG tnc (pid 187): found 1, lvl 0, n 0
<7>UBIFS DBG lp (pid 187): LEB 615, free 102400, dirty 411576, flags 1
<7>UBIFS DBG lp (pid 187): LEB 615, free -2147483647, dirty 411736, flags 1
<7>UBIFS DBG lp (pid 187): LEB 615, free 102400, dirty 411576, flags 1
<7>UBIFS DBG mnt (pid 187): LEB 615:421888 len 97 deletion 0 sqnum 378720 key (68, direntry, 0x177c167)
<7>UBIFS DBG tnc (pid 187): LEB 615:421888, name '03c0ab4a5f384344b519675547035c5a-runtime', key (68, direntry, 0x177c167)
<7>UBIFS DBG tnc (pid 187): search and dirty key (68, direntry, 0x177c167)
<7>UBIFS DBG io (pid 187): LEB 595:221448, indexing node, length 108
<7>UBI DBG gen (pid 187): read 108 bytes from LEB 0:595:221448
<7>UBI DBG eba (pid 187): read 108 bytes from offset 221448 of LEB 0:595, PEB 684
<7>UBI DBG io (pid 187): read 108 bytes from PEB 684:229640
<7>UBIFS DBG tnc (pid 187): LEB 595:221448, level 1, 4 branch
<7>UBI DBG gen (pid 187): read 13 bytes from LEB 0:6:491551
<7>UBI DBG eba (pid 187): read 13 bytes from offset 491551 of LEB 0:6, PEB 964
<7>UBI DBG io (pid 187): read 13 bytes from PEB 964:499743
<7>UBIFS DBG lp (pid 187): LEB 6 add 13 to 495130
<7>UBI DBG gen (pid 187): read 19 bytes from LEB 0:6:372793
<7>UBI DBG eba (pid 187): read 19 bytes from offset 372793 of LEB 0:6, PEB 964
<7>UBI DBG io (pid 187): read 19 bytes from PEB 964:380985
<7>UBIFS DBG lp (pid 187): LEB 6 add 19 to 495143
<7>UBIFS DBG lp (pid 187): LEB 595, free 0, dirty 511944, flags 34
<7>UBIFS DBG lp (pid 187): LEB 595, free -2147483647, dirty 512052, flags 34
<7>UBIFS DBG lp (pid 187): LEB 595, free 0, dirty 511944, flags 34
<7>UBIFS DBG io (pid 187): LEB 562:372960, indexing node, length 148
<7>UBI DBG gen (pid 187): read 148 bytes from LEB 0:562:372960
<7>UBI DBG eba (pid 187): read 148 bytes from offset 372960 of LEB 0:562, PEB 712
<7>UBI DBG io (pid 187): read 148 bytes from PEB 712:381152
<7>UBIFS DBG tnc (pid 187): LEB 562:372960, level 0, 6 branch
<7>UBI DBG gen (pid 187): read 13 bytes from LEB 0:6:475212
<7>UBI DBG eba (pid 187): read 13 bytes from offset 475212 of LEB 0:6, PEB 964
<7>UBI DBG io (pid 187): read 13 bytes from PEB 964:483404
<7>UBIFS DBG lp (pid 187): LEB 6 add 13 to 495162
<7>UBI DBG gen (pid 187): read 13 bytes from LEB 0:6:475167
<7>UBI DBG eba (pid 187): read 13 bytes from offset 475167 of LEB 0:6, PEB 964
<7>UBI DBG io (pid 187): read 13 bytes from PEB 964:483359
<7>UBIFS DBG lp (pid 187): LEB 6 add 13 to 495175
<7>UBI DBG gen (pid 187): read 19 bytes from LEB 0:6:372748
<7>UBI DBG eba (pid 187): read 19 bytes from offset 372748 of LEB 0:6, PEB 964
<7>UBI DBG io (pid 187): read 19 bytes from PEB 964:380940
<7>UBIFS DBG lp (pid 187): LEB 6 add 19 to 495188
<7>UBIFS DBG lp (pid 187): LEB 562, free 0, dirty 514456, flags 34
<7>UBIFS DBG lp (pid 187): LEB 562, free -2147483647, dirty 514604, flags 34
<7>UBIFS DBG lp (pid 187): LEB 562, free 0, dirty 514456, flags 34
<7>UBIFS DBG tnc (pid 187): found 0, lvl 0, n 3
<7>UBIFS DBG tnc (pid 187): inserted at 4 level 0, key (68, direntry, 0x177c167)
<7>UBIFS DBG tnc (pid 187): , key (68, direntry, 0x177c167)
<7>UBIFS DBG tnc (pid 187): search and dirty key (68, direntry, 0x177c167)
<7>UBIFS DBG tnc (pid 187): found 1, lvl 0, n 4
<7>UBIFS DBG tnc (pid 187): LEB 615:421888, key (68, direntry, 0x177c167)
<7>UBIFS DBG io (pid 187): LEB 615:421888, direntry node, length 97
<7>UBI DBG gen (pid 187): read 97 bytes from LEB 0:615:421888
<7>UBI DBG eba (pid 187): read 97 bytes from offset 421888 of LEB 0:615, PEB 694
<7>UBI DBG io (pid 187): read 97 bytes from PEB 694:430080
<7>UBIFS DBG tnc (pid 187): rc returned 0, znode a8c4dd00, n 4
<7>UBIFS DBG mnt (pid 187): LEB 615:421992 len 183 deletion 0 sqnum 378721 key (6568, inode)
<7>UBIFS DBG tnc (pid 187): 615:421992, len 183, key (6568, inode)
<7>UBIFS DBG tnc (pid 187): search and dirty key (6568, inode)
<7>UBIFS DBG io (pid 187): LEB 614:374024, indexing node, length 128
<7>UBI DBG gen (pid 187): read 128 bytes from LEB 0:614:374024
<7>UBI DBG eba (pid 187): read 128 bytes from offset 374024 of LEB 0:614, PEB 973
<7>UBI DBG io (pid 187): read 128 bytes from PEB 973:382216
<7>UBIFS DBG tnc (pid 187): LEB 614:374024, level 4, 5 branch
<7>UBIFS DBG lp (pid 187): LEB 614, free 131072, dirty 374864, flags 48
<7>UBIFS DBG lp (pid 187): LEB 614, free -2147483647, dirty 374992, flags 48
<7>UBIFS DBG lp (pid 187): LEB 614, free 131072, dirty 374864, flags 48
<7>UBIFS DBG io (pid 187): LEB 614:373872, indexing node, length 148
<7>UBI DBG gen (pid 187): read 148 bytes from LEB 0:614:373872
<7>UBI DBG eba (pid 187): read 148 bytes from offset 373872 of LEB 0:614, PEB 973
<7>UBI DBG io (pid 187): read 148 bytes from PEB 973:382064
<7>UBIFS DBG tnc (pid 187): LEB 614:373872, level 2, 6 branch
<3>UBIFS error (pid 187): read_znode: bad key type at slot 0: 5
<3>UBIFS error (pid 187): read_znode: bad indexing node at LEB 614:373872, error 3
<3> magic 0x6101831
<3> crc 0x944add59
<3> node_type 9 (indexing node)
<3> group_type 0 (no node group)
<3> sqnum 378678
<3> len 148
<3> child_cnt 6
<3> level 2
<3> Branches:
<3> 0: LEB 569:280144 len 108 key (bad key type: 0x000001, 0xa917dd4c)
<3> 1: LEB 446:349792 len 108 key (5595, inode)
<3> 2: LEB 584:361528 len 108 key (5822, inode)
<3> 3: LEB 602:255360 len 108 key (6050, inode)
<3> 4: LEB 613:480280 len 188 key (6258, inode)
<3> 5: LEB 614:373784 len 88 key (6521, data, 25)
<5>UBIFS: background thread "ubifs_bgt7_0" stops
<7>UBI DBG gen (pid 187): close device 7, volume 0, mode 2
<7>UBI DBG gen (pid 187): close device 7, volume 0, mode 1
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: UBIFS Index Node Corruption - Invalid Key Type
2016-05-10 12:14 UBIFS Index Node Corruption - Invalid Key Type DHANAPAL, GNANACHANDRAN (G.)
@ 2016-05-10 13:58 ` Richard Weinberger
2016-05-10 14:49 ` DHANAPAL, GNANACHANDRAN (G.)
0 siblings, 1 reply; 15+ messages in thread
From: Richard Weinberger @ 2016-05-10 13:58 UTC (permalink / raw)
To: DHANAPAL, GNANACHANDRAN (G.)
Cc: linux-mtd, CN, Aananth (A.A.), Gunasundar, Balamanikandan (B.),
Babu, Viswanathan (V.),
Artem Bityutskiy, Adrian Hunter, gnanachandran
On Tue, May 10, 2016 at 2:14 PM, DHANAPAL, GNANACHANDRAN (G.)
<gdhanapa@visteon.com> wrote:
> Hi There,
>
> We have i.MX6d based platform that has FSL BSP 3.10.17 running.
> There is SLC Micron NAND of size 2GB with 512K Block size and 4K min I/O used
> for software storage. This NAND has got 7 partitions, Among that two partitions
> have Read-Write ubifs file system for runtime data and one has Read-only ubifs
> file system that has all the system files. Recently we have observed a issue that
> one of RW ubifs partition failed to mount due to invalid key type in one of index
> node in ubifs. we have seen the same issue in two units out of 1000 units running
> in the field.
>
> Following is the index node that has invalid key in its first branch.
> key type = 0xa917dd4c >> 29 = 5 (invalid key)
>
> magic 0x6101831
> crc 0x944add59
> node_type 9 (indexing node)
> group_type 0 (no node group)
> sqnum 378678
> len 148
> child_cnt 6
> level 2
> Branches:
> 0: LEB 569:280144 len 108 key (bad key type: 0x000001, 0xa917dd4c)
> 1: LEB 446:349792 len 108 key (5595, inode)
> 2: LEB 584:361528 len 108 key (5822, inode)
> 3: LEB 602:255360 len 108 key (6050, inode)
> 4: LEB 613:480280 len 188 key (6258, inode)
> 5: LEB 614:373784 len 88 key (6521, data, 25)
>
> Please help us to understand following points
>
> 1. Did this happen because abrupt power cut ? if so, how could CRC of the node still be intact?
> 2. Could there be any bit flip ? but still again CRC intact.
> 3. Would the key pointed by corrupted branch be UBIFS_DENT_KEY or UBIFS_XENT_KEY ?
> Because 29 bit of key[0] (0xa917dd4c & 0x1FFFFFFF) seems to have some kind of hash value.
> but node (at leb 569:280144) that is pointed by corrupted branch seem to be index node.
> 4. This corrupted entry is always seen in first branch of an index node in two failed units. Could there be reason?
> 5. Since CRC is intact, would there be any possibility or scenario that corrupted node can be written with valid CRC?
Hmm, this looks like some UBIFS inconsistency.
If the header CRC is correct it should be be any kind of bitflip or
power cut issue.
Can you please share the whole UBI image (a nanddump) such that I can
inspect it?
--
Thanks,
//richard
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: UBIFS Index Node Corruption - Invalid Key Type
2016-05-10 13:58 ` Richard Weinberger
@ 2016-05-10 14:49 ` DHANAPAL, GNANACHANDRAN (G.)
2016-05-10 16:23 ` Richard Weinberger
2016-05-10 16:48 ` Richard Weinberger
0 siblings, 2 replies; 15+ messages in thread
From: DHANAPAL, GNANACHANDRAN (G.) @ 2016-05-10 14:49 UTC (permalink / raw)
To: Richard Weinberger
Cc: CN, Aananth (A.A.), Gunasundar, Balamanikandan (B.),
Babu, Viswanathan (V.),
dedekind1, adrian.hunter, linux-mtd, gnanachandran
On Tue, May 10, 2016 at 03:58:58PM +0200, Richard Weinberger wrote:
> On Tue, May 10, 2016 at 2:14 PM, DHANAPAL, GNANACHANDRAN (G.)
> <gdhanapa@visteon.com> wrote:
> > Hi There,
> >
> > We have i.MX6d based platform that has FSL BSP 3.10.17 running.
> > There is SLC Micron NAND of size 2GB with 512K Block size and 4K min I/O used
> > for software storage. This NAND has got 7 partitions, Among that two partitions
> > have Read-Write ubifs file system for runtime data and one has Read-only ubifs
> > file system that has all the system files. Recently we have observed a issue that
> > one of RW ubifs partition failed to mount due to invalid key type in one of index
> > node in ubifs. we have seen the same issue in two units out of 1000 units running
> > in the field.
> >
> > Following is the index node that has invalid key in its first branch.
> > key type = 0xa917dd4c >> 29 = 5 (invalid key)
> >
> > magic 0x6101831
> > crc 0x944add59
> > node_type 9 (indexing node)
> > group_type 0 (no node group)
> > sqnum 378678
> > len 148
> > child_cnt 6
> > level 2
> > Branches:
> > 0: LEB 569:280144 len 108 key (bad key type: 0x000001, 0xa917dd4c)
> > 1: LEB 446:349792 len 108 key (5595, inode)
> > 2: LEB 584:361528 len 108 key (5822, inode)
> > 3: LEB 602:255360 len 108 key (6050, inode)
> > 4: LEB 613:480280 len 188 key (6258, inode)
> > 5: LEB 614:373784 len 88 key (6521, data, 25)
> >
> > Please help us to understand following points
> >
> > 1. Did this happen because abrupt power cut ? if so, how could CRC of the node still be intact?
> > 2. Could there be any bit flip ? but still again CRC intact.
> > 3. Would the key pointed by corrupted branch be UBIFS_DENT_KEY or UBIFS_XENT_KEY ?
> > Because 29 bit of key[0] (0xa917dd4c & 0x1FFFFFFF) seems to have some kind of hash value.
> > but node (at leb 569:280144) that is pointed by corrupted branch seem to be index node.
> > 4. This corrupted entry is always seen in first branch of an index node in two failed units. Could there be reason?
> > 5. Since CRC is intact, would there be any possibility or scenario that corrupted node can be written with valid CRC?
>
> Hmm, this looks like some UBIFS inconsistency.
> If the header CRC is correct it should be be any kind of bitflip or
> power cut issue.
>
> Can you please share the whole UBI image (a nanddump) such that I can
> inspect it?
>
> --
> Thanks,
> //richard
Thanks for the reply, Richard.
Please find two files in google drive share.
1. dump_mtd7_ecc.log - /dev/mtd7 dump with ecc
2. leb_peb_map_22706.log - LEB to PEB map. This information is taken by having print in table.
Share:
https://drive.google.com/open?id=0B7tYZDLZ_KAZMFd4MENlQkJuNjA
Cheers
Gnana
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: UBIFS Index Node Corruption - Invalid Key Type
2016-05-10 14:49 ` DHANAPAL, GNANACHANDRAN (G.)
@ 2016-05-10 16:23 ` Richard Weinberger
2016-05-10 16:48 ` Richard Weinberger
1 sibling, 0 replies; 15+ messages in thread
From: Richard Weinberger @ 2016-05-10 16:23 UTC (permalink / raw)
To: DHANAPAL, GNANACHANDRAN (G.)
Cc: CN, Aananth (A.A.), Gunasundar, Balamanikandan (B.),
Babu, Viswanathan (V.),
dedekind1, adrian.hunter, linux-mtd, gnanachandran
Am 10.05.2016 um 16:49 schrieb DHANAPAL, GNANACHANDRAN (G.):
> On Tue, May 10, 2016 at 03:58:58PM +0200, Richard Weinberger wrote:
>> On Tue, May 10, 2016 at 2:14 PM, DHANAPAL, GNANACHANDRAN (G.)
>> <gdhanapa@visteon.com> wrote:
>>> Hi There,
>>>
>>> We have i.MX6d based platform that has FSL BSP 3.10.17 running.
>>> There is SLC Micron NAND of size 2GB with 512K Block size and 4K min I/O used
>>> for software storage. This NAND has got 7 partitions, Among that two partitions
>>> have Read-Write ubifs file system for runtime data and one has Read-only ubifs
>>> file system that has all the system files. Recently we have observed a issue that
>>> one of RW ubifs partition failed to mount due to invalid key type in one of index
>>> node in ubifs. we have seen the same issue in two units out of 1000 units running
>>> in the field.
>>>
>>> Following is the index node that has invalid key in its first branch.
>>> key type = 0xa917dd4c >> 29 = 5 (invalid key)
>>>
>>> magic 0x6101831
>>> crc 0x944add59
>>> node_type 9 (indexing node)
>>> group_type 0 (no node group)
>>> sqnum 378678
>>> len 148
>>> child_cnt 6
>>> level 2
>>> Branches:
>>> 0: LEB 569:280144 len 108 key (bad key type: 0x000001, 0xa917dd4c)
>>> 1: LEB 446:349792 len 108 key (5595, inode)
>>> 2: LEB 584:361528 len 108 key (5822, inode)
>>> 3: LEB 602:255360 len 108 key (6050, inode)
>>> 4: LEB 613:480280 len 188 key (6258, inode)
>>> 5: LEB 614:373784 len 88 key (6521, data, 25)
>>>
>>> Please help us to understand following points
>>>
>>> 1. Did this happen because abrupt power cut ? if so, how could CRC of the node still be intact?
>>> 2. Could there be any bit flip ? but still again CRC intact.
>>> 3. Would the key pointed by corrupted branch be UBIFS_DENT_KEY or UBIFS_XENT_KEY ?
>>> Because 29 bit of key[0] (0xa917dd4c & 0x1FFFFFFF) seems to have some kind of hash value.
>>> but node (at leb 569:280144) that is pointed by corrupted branch seem to be index node.
>>> 4. This corrupted entry is always seen in first branch of an index node in two failed units. Could there be reason?
>>> 5. Since CRC is intact, would there be any possibility or scenario that corrupted node can be written with valid CRC?
>>
>> Hmm, this looks like some UBIFS inconsistency.
>> If the header CRC is correct it should be be any kind of bitflip or
>> power cut issue.
Of course I meant shouldn't. :-)
>> Can you please share the whole UBI image (a nanddump) such that I can
>> inspect it?
>>
>> --
>> Thanks,
>> //richard
>
> Thanks for the reply, Richard.
> Please find two files in google drive share.
>
> 1. dump_mtd7_ecc.log - /dev/mtd7 dump with ecc
> 2. leb_peb_map_22706.log - LEB to PEB map. This information is taken by having print in table.
>
> Share:
> https://drive.google.com/open?id=0B7tYZDLZ_KAZMFd4MENlQkJuNjA
Okay, I'll look. Can't promise that I have the time for a detailed analysis.
Thanks,
//richard
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: UBIFS Index Node Corruption - Invalid Key Type
2016-05-10 14:49 ` DHANAPAL, GNANACHANDRAN (G.)
2016-05-10 16:23 ` Richard Weinberger
@ 2016-05-10 16:48 ` Richard Weinberger
[not found] ` <20160511065223.GA22220@visteon-gnana>
1 sibling, 1 reply; 15+ messages in thread
From: Richard Weinberger @ 2016-05-10 16:48 UTC (permalink / raw)
To: DHANAPAL, GNANACHANDRAN (G.), Richard Weinberger
Cc: CN, Aananth (A.A.), Gunasundar, Balamanikandan (B.),
Babu, Viswanathan (V.),
dedekind1, adrian.hunter, linux-mtd, gnanachandran
Am 10.05.2016 um 16:49 schrieb DHANAPAL, GNANACHANDRAN (G.):
> Thanks for the reply, Richard.
> Please find two files in google drive share.
>
> 1. dump_mtd7_ecc.log - /dev/mtd7 dump with ecc
> 2. leb_peb_map_22706.log - LEB to PEB map. This information is taken by having print in table.
>
> Share:
> https://drive.google.com/open?id=0B7tYZDLZ_KAZMFd4MENlQkJuNjA
Hmm, the share contains only log files.
I need a pristine dump of your NAND (created by nanddump without OOB data) to analyze the issue.
Thanks,
//richard
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: UBIFS Index Node Corruption - Invalid Key Type
[not found] ` <20160511065223.GA22220@visteon-gnana>
@ 2016-05-11 7:29 ` DHANAPAL, GNANACHANDRAN (G.)
2016-05-11 9:22 ` Richard Weinberger
0 siblings, 1 reply; 15+ messages in thread
From: DHANAPAL, GNANACHANDRAN (G.) @ 2016-05-11 7:29 UTC (permalink / raw)
To: Richard Weinberger
Cc: CN, Aananth (A.A.), Gunasundar, Balamanikandan (B.),
Babu, Viswanathan (V.),
dedekind1, adrian.hunter, linux-mtd, gnanachandran
On Wed, May 11, 2016 at 12:22:23PM +0530, Gnanachandran Dhanapal wrote:
> On Tue, May 10, 2016 at 06:48:24PM +0200, Richard Weinberger wrote:
> > Am 10.05.2016 um 16:49 schrieb DHANAPAL, GNANACHANDRAN (G.):
> > > Thanks for the reply, Richard.
> > > Please find two files in google drive share.
> > >
> > > 1. dump_mtd7_ecc.log - /dev/mtd7 dump with ecc
> > > 2. leb_peb_map_22706.log - LEB to PEB map. This information is taken by having print in table.
> > >
> > > Share:
> > > https://drive.google.com/open?id=0B7tYZDLZ_KAZMFd4MENlQkJuNjA
> >
> > Hmm, the share contains only log files.
> > I need a pristine dump of your NAND (created by nanddump without OOB data) to analyze the issue.
> >
> > Thanks,
> > //richard
>
> Sorry Richard, The file name or its extension "dump_mtd7_ecc.log" might be confusing. but actually this file was created using
> command "nanddump /dev/mtd7 -f dump_mtd7_ecc.log". This file of size 510MB.
>
> dump_mtd7_ecc.log MD5SUM = 5b04c52f992036047d426fa07691429e
> SHA256SUM = 28a36d3fc28c18adc29be66525c1a28e68143937ec43be425ee942d3375c17a6
>
> Please let me know if you have any issue accessing the file.
>
> Cheers
> Gnana
Copying CC list
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: UBIFS Index Node Corruption - Invalid Key Type
2016-05-11 7:29 ` DHANAPAL, GNANACHANDRAN (G.)
@ 2016-05-11 9:22 ` Richard Weinberger
2016-05-11 11:16 ` DHANAPAL, GNANACHANDRAN (G.)
0 siblings, 1 reply; 15+ messages in thread
From: Richard Weinberger @ 2016-05-11 9:22 UTC (permalink / raw)
To: DHANAPAL, GNANACHANDRAN (G.)
Cc: CN, Aananth (A.A.), Gunasundar, Balamanikandan (B.),
Babu, Viswanathan (V.),
dedekind1, adrian.hunter, linux-mtd, gnanachandran
Am 11.05.2016 um 09:29 schrieb DHANAPAL, GNANACHANDRAN (G.):
> On Wed, May 11, 2016 at 12:22:23PM +0530, Gnanachandran Dhanapal wrote:
>> On Tue, May 10, 2016 at 06:48:24PM +0200, Richard Weinberger wrote:
>>> Am 10.05.2016 um 16:49 schrieb DHANAPAL, GNANACHANDRAN (G.):
>>>> Thanks for the reply, Richard.
>>>> Please find two files in google drive share.
>>>>
>>>> 1. dump_mtd7_ecc.log - /dev/mtd7 dump with ecc
>>>> 2. leb_peb_map_22706.log - LEB to PEB map. This information is taken by having print in table.
>>>>
>>>> Share:
>>>> https://drive.google.com/open?id=0B7tYZDLZ_KAZMFd4MENlQkJuNjA
>>>
>>> Hmm, the share contains only log files.
>>> I need a pristine dump of your NAND (created by nanddump without OOB data) to analyze the issue.
>>>
>>> Thanks,
>>> //richard
>>
>> Sorry Richard, The file name or its extension "dump_mtd7_ecc.log" might be confusing. but actually this file was created using
>> command "nanddump /dev/mtd7 -f dump_mtd7_ecc.log". This file of size 510MB.
>>
>> dump_mtd7_ecc.log MD5SUM = 5b04c52f992036047d426fa07691429e
>> SHA256SUM = 28a36d3fc28c18adc29be66525c1a28e68143937ec43be425ee942d3375c17a6
>>
>> Please let me know if you have any issue accessing the file.
Ahh, .log for a dump file, creative naming. ;-)
I had a brief look, the provided dump has more problems.
The dent node with the bad type is not referenced by the journal,
so we can ignore it for now.
The worse problem is that the index references a lot of non-existing
inodes.
Is this a pristine UBIFS with all fixes applied?
Your kernel is rather old. Not sure if we ever had such an issue,
but still...
Can you please explain a bit more what your device is doing and what
NAND/UBI layout you are using?
Thanks,
//richard
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: UBIFS Index Node Corruption - Invalid Key Type
2016-05-11 9:22 ` Richard Weinberger
@ 2016-05-11 11:16 ` DHANAPAL, GNANACHANDRAN (G.)
2016-05-11 12:42 ` Richard Weinberger
2016-05-11 14:47 ` Richard Weinberger
0 siblings, 2 replies; 15+ messages in thread
From: DHANAPAL, GNANACHANDRAN (G.) @ 2016-05-11 11:16 UTC (permalink / raw)
To: Richard Weinberger
Cc: CN, Aananth (A.A.), Gunasundar, Balamanikandan (B.),
babu3, dedekind1, adrian.hunter, linux-mtd, gnanachandran
On Wed, May 11, 2016 at 11:22:15AM +0200, Richard Weinberger wrote:
> Am 11.05.2016 um 09:29 schrieb DHANAPAL, GNANACHANDRAN (G.):
> > On Wed, May 11, 2016 at 12:22:23PM +0530, Gnanachandran Dhanapal wrote:
> >> On Tue, May 10, 2016 at 06:48:24PM +0200, Richard Weinberger wrote:
> >>> Am 10.05.2016 um 16:49 schrieb DHANAPAL, GNANACHANDRAN (G.):
> >>>> Thanks for the reply, Richard.
> >>>> Please find two files in google drive share.
> >>>>
> >>>> 1. dump_mtd7_ecc.log - /dev/mtd7 dump with ecc
> >>>> 2. leb_peb_map_22706.log - LEB to PEB map. This information is taken by having print in table.
> >>>>
> >>>> Share:
> >>>> https://drive.google.com/open?id=0B7tYZDLZ_KAZMFd4MENlQkJuNjA
> >>>
> >>> Hmm, the share contains only log files.
> >>> I need a pristine dump of your NAND (created by nanddump without OOB data) to analyze the issue.
> >>>
> >>> Thanks,
> >>> //richard
> >>
> >> Sorry Richard, The file name or its extension "dump_mtd7_ecc.log" might be confusing. but actually this file was created using
> >> command "nanddump /dev/mtd7 -f dump_mtd7_ecc.log". This file of size 510MB.
> >>
> >> dump_mtd7_ecc.log MD5SUM = 5b04c52f992036047d426fa07691429e
> >> SHA256SUM = 28a36d3fc28c18adc29be66525c1a28e68143937ec43be425ee942d3375c17a6
> >>
> >> Please let me know if you have any issue accessing the file.
>
> Ahh, .log for a dump file, creative naming. ;-)
>
> I had a brief look, the provided dump has more problems.
> The dent node with the bad type is not referenced by the journal,
> so we can ignore it for now.
> The worse problem is that the index references a lot of non-existing
> inodes.
>
> Is this a pristine UBIFS with all fixes applied?
> Your kernel is rather old. Not sure if we ever had such an issue,
Yes, This is pretty much older one provided by chip vendor NXP(Freescale) BSP 3.10.17.
Last commit id for ubifs is
commit 4791df938fe7aa27a9fe50e4582efd583a045541
Author: Richard Genoud <richard.genoud@gmail.com>
Date: Tue Apr 2 12:24:37 2013 +0200
Last commit id for ubi is
commit d779146e04aacc8abe8d645284388c837d5d50cd
Author: Huang Shijie <b32955@freescale.com>
Date: Wed Sep 18 10:17:39 2013 +0800
> but still...
> Can you please explain a bit more what your device is doing and what
> NAND/UBI layout you are using?
This is an automotive infotainment system that has 5 raw partitions for
u-boot, kernel and recovery software. And there are 3 ubifs partitions for
1. / - (RO) - 896 MB,
2. /var - (RW) - 128 MB,
3. /meta - (RW)- 512 MB.
All of these partition has been through following commands (in order) for
ubifs file system creation during production.
1. ubiformat
2. ubimkvol
3. ubiattach
4. mount -t ubifs
A rootfs tar file from yocto build output files was untar in / and /var partitions.
/meta partition is configured as home folder that has runtime files for
pulseaudio, gstreamer, infotainment radio tuner alignment and radio channel preset.
this partition also has mount point for USB storage device. Where the user can plug
and unplug their USB flash pen drive without umount -ing it. This is the partition
that got corrupted in two units out of 1000 units in vehicles that has running for
last 6 months.
>
> Thanks,
> //richard
Cheers
Gnana
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: UBIFS Index Node Corruption - Invalid Key Type
2016-05-11 11:16 ` DHANAPAL, GNANACHANDRAN (G.)
@ 2016-05-11 12:42 ` Richard Weinberger
2016-05-11 14:47 ` Richard Weinberger
1 sibling, 0 replies; 15+ messages in thread
From: Richard Weinberger @ 2016-05-11 12:42 UTC (permalink / raw)
To: DHANAPAL, GNANACHANDRAN (G.)
Cc: CN, Aananth (A.A.), Gunasundar, Balamanikandan (B.),
babu3, dedekind1, adrian.hunter, linux-mtd, gnanachandran
Am 11.05.2016 um 13:16 schrieb DHANAPAL, GNANACHANDRAN (G.):
>> Is this a pristine UBIFS with all fixes applied?
>> Your kernel is rather old. Not sure if we ever had such an issue,
> Yes, This is pretty much older one provided by chip vendor NXP(Freescale) BSP 3.10.17.
> Last commit id for ubifs is
>
> commit 4791df938fe7aa27a9fe50e4582efd583a045541
> Author: Richard Genoud <richard.genoud@gmail.com>
> Date: Tue Apr 2 12:24:37 2013 +0200
>
> Last commit id for ubi is
>
> commit d779146e04aacc8abe8d645284388c837d5d50cd
> Author: Huang Shijie <b32955@freescale.com>
> Date: Wed Sep 18 10:17:39 2013 +0800
rw@sandpuppy:~/linux (master $)> git show d779146e04aacc8abe8d645284388c837d5d50cd
fatal: bad object d779146e04aacc8abe8d645284388c837d5d50cd
For both commits. So, a rebased tree.
:-(
>
>> but still...
>> Can you please explain a bit more what your device is doing and what
>> NAND/UBI layout you are using?
> This is an automotive infotainment system that has 5 raw partitions for
> u-boot, kernel and recovery software. And there are 3 ubifs partitions for
> 1. / - (RO) - 896 MB,
> 2. /var - (RW) - 128 MB,
> 3. /meta - (RW)- 512 MB.
>
> All of these partition has been through following commands (in order) for
> ubifs file system creation during production.
> 1. ubiformat
> 2. ubimkvol
> 3. ubiattach
> 4. mount -t ubifs
> A rootfs tar file from yocto build output files was untar in / and /var partitions.
>
>
> /meta partition is configured as home folder that has runtime files for
> pulseaudio, gstreamer, infotainment radio tuner alignment and radio channel preset.
> this partition also has mount point for USB storage device. Where the user can plug
> and unplug their USB flash pen drive without umount -ing it. This is the partition
> that got corrupted in two units out of 1000 units in vehicles that has running for
> last 6 months.
What exactly is the error message you get from the kernel while mounting?
Something like "bad node type (255 but expected 9)"?
It seems like some LEBs are erased with shouldn't.
Thanks,
//richard
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: UBIFS Index Node Corruption - Invalid Key Type
2016-05-11 11:16 ` DHANAPAL, GNANACHANDRAN (G.)
2016-05-11 12:42 ` Richard Weinberger
@ 2016-05-11 14:47 ` Richard Weinberger
2016-05-12 13:29 ` Richard Weinberger
1 sibling, 1 reply; 15+ messages in thread
From: Richard Weinberger @ 2016-05-11 14:47 UTC (permalink / raw)
To: DHANAPAL, GNANACHANDRAN (G.)
Cc: CN, Aananth (A.A.), Gunasundar, Balamanikandan (B.),
babu3, dedekind1, adrian.hunter, linux-mtd, gnanachandran
Am 11.05.2016 um 13:16 schrieb DHANAPAL, GNANACHANDRAN (G.):
> On Wed, May 11, 2016 at 11:22:15AM +0200, Richard Weinberger wrote:
>> I had a brief look, the provided dump has more problems.
>> The dent node with the bad type is not referenced by the journal,
>> so we can ignore it for now.
>> The worse problem is that the index references a lot of non-existing
>> inodes.
BTW: Do both MTD tests and UBI tests pass?
Thanks,
//richard
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: UBIFS Index Node Corruption - Invalid Key Type
2016-05-11 14:47 ` Richard Weinberger
@ 2016-05-12 13:29 ` Richard Weinberger
2016-05-13 9:40 ` DHANAPAL, GNANACHANDRAN (G.)
0 siblings, 1 reply; 15+ messages in thread
From: Richard Weinberger @ 2016-05-12 13:29 UTC (permalink / raw)
To: DHANAPAL, GNANACHANDRAN (G.)
Cc: CN, Aananth (A.A.), Gunasundar, Balamanikandan (B.),
babu3, dedekind1, adrian.hunter, linux-mtd, gnanachandran
Am 11.05.2016 um 16:47 schrieb Richard Weinberger:
> Am 11.05.2016 um 13:16 schrieb DHANAPAL, GNANACHANDRAN (G.):
>> On Wed, May 11, 2016 at 11:22:15AM +0200, Richard Weinberger wrote:
>>> I had a brief look, the provided dump has more problems.
>>> The dent node with the bad type is not referenced by the journal,
>>> so we can ignore it for now.
>>> The worse problem is that the index references a lot of non-existing
>>> inodes.
>
> BTW: Do both MTD tests and UBI tests pass?
Gave your issue another thought.
It is possible that you're facing bitflips in UBIFS meta data
which is not covered by the header CRC.
At least this would explain the corruption pattern you're facing.
Thanks,
//richard
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: UBIFS Index Node Corruption - Invalid Key Type
2016-05-12 13:29 ` Richard Weinberger
@ 2016-05-13 9:40 ` DHANAPAL, GNANACHANDRAN (G.)
2016-05-13 13:54 ` Richard Weinberger
0 siblings, 1 reply; 15+ messages in thread
From: DHANAPAL, GNANACHANDRAN (G.) @ 2016-05-13 9:40 UTC (permalink / raw)
To: Richard Weinberger
Cc: CN, Aananth (A.A.), Gunasundar, Balamanikandan (B.),
Babu, Viswanathan (V.),
dedekind1, adrian.hunter, linux-mtd, gnanachandran
On Thu, May 12, 2016 at 03:29:56PM +0200, Richard Weinberger wrote:
> Am 11.05.2016 um 16:47 schrieb Richard Weinberger:
> > Am 11.05.2016 um 13:16 schrieb DHANAPAL, GNANACHANDRAN (G.):
> >> On Wed, May 11, 2016 at 11:22:15AM +0200, Richard Weinberger wrote:
> >>> I had a brief look, the provided dump has more problems.
> >>> The dent node with the bad type is not referenced by the journal,
> >>> so we can ignore it for now.
> >>> The worse problem is that the index references a lot of non-existing
> >>> inodes.
> >
> > BTW: Do both MTD tests and UBI tests pass?
>
> Gave your issue another thought.
> It is possible that you're facing bitflips in UBIFS meta data
> which is not covered by the header CRC.
> At least this would explain the corruption pattern you're facing.
>
> Thanks,
> //richard
Richard,
I believe CRC value for a node is calculated in RAM before writing the node in NAND.
In this case, node CRC and calculated CRC are matching. so Will there be possibility
for corrupting key type area (32 bits) and keeping others intacted. or any other
possibility for node getting corrupted.
This system is configured for 16 bit ecc strength including 10 bytes metadata in DATA0.
This NAND has 4K i/o Size and 224 OOB size.
Cheers
Gnana
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: UBIFS Index Node Corruption - Invalid Key Type
2016-05-13 9:40 ` DHANAPAL, GNANACHANDRAN (G.)
@ 2016-05-13 13:54 ` Richard Weinberger
2016-05-13 16:02 ` DHANAPAL, GNANACHANDRAN (G.)
2016-05-13 16:03 ` CN, Aananth (A.A.)
0 siblings, 2 replies; 15+ messages in thread
From: Richard Weinberger @ 2016-05-13 13:54 UTC (permalink / raw)
To: DHANAPAL, GNANACHANDRAN (G.)
Cc: CN, Aananth (A.A.), Gunasundar, Balamanikandan (B.),
Babu, Viswanathan (V.),
dedekind1, adrian.hunter, linux-mtd, gnanachandran
Am 13.05.2016 um 11:40 schrieb DHANAPAL, GNANACHANDRAN (G.):
> Richard,
>
> I believe CRC value for a node is calculated in RAM before writing the node in NAND.
> In this case, node CRC and calculated CRC are matching. so Will there be possibility
> for corrupting key type area (32 bits) and keeping others intacted. or any other
> possibility for node getting corrupted.
I have to correct myself, the branches of an index node are covered by
the node header CRC.
This makes the whole picture more strange.
You said you're facing the same issue on another unit.
Is the corruption really the same? Bad key type 5?
Thanks,
//richard
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: UBIFS Index Node Corruption - Invalid Key Type
2016-05-13 13:54 ` Richard Weinberger
@ 2016-05-13 16:02 ` DHANAPAL, GNANACHANDRAN (G.)
2016-05-13 16:03 ` CN, Aananth (A.A.)
1 sibling, 0 replies; 15+ messages in thread
From: DHANAPAL, GNANACHANDRAN (G.) @ 2016-05-13 16:02 UTC (permalink / raw)
To: Richard Weinberger
Cc: CN, Aananth (A.A.), Gunasundar, Balamanikandan (B.),
Babu, Viswanathan (V.),
dedekind1, adrian.hunter, linux-mtd, gnanachandran
On Fri, May 13, 2016 at 03:54:10PM +0200, Richard Weinberger wrote:
> Am 13.05.2016 um 11:40 schrieb DHANAPAL, GNANACHANDRAN (G.):
> > Richard,
> >
> > I believe CRC value for a node is calculated in RAM before writing the node in NAND.
> > In this case, node CRC and calculated CRC are matching. so Will there be possibility
> > for corrupting key type area (32 bits) and keeping others intacted. or any other
> > possibility for node getting corrupted.
>
> I have to correct myself, the branches of an index node are covered by
> the node header CRC.
> This makes the whole picture more strange.
>
> You said you're facing the same issue on another unit.
> Is the corruption really the same? Bad key type 5?
>
> Thanks,
> //richard
Yes Richard, We have received two more units for exactly same issues and same bad key type 5.
Cheers
Gnana
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: UBIFS Index Node Corruption - Invalid Key Type
2016-05-13 13:54 ` Richard Weinberger
2016-05-13 16:02 ` DHANAPAL, GNANACHANDRAN (G.)
@ 2016-05-13 16:03 ` CN, Aananth (A.A.)
1 sibling, 0 replies; 15+ messages in thread
From: CN, Aananth (A.A.) @ 2016-05-13 16:03 UTC (permalink / raw)
To: Richard Weinberger
Cc: DHANAPAL, GNANACHANDRAN (G.), Gunasundar, Balamanikandan (B.),
Babu, Viswanathan (V.),
dedekind1, adrian.hunter, linux-mtd, gnanachandran
Hi Richard,
Yes, it is the same bad key type 5.
Additional hint is, the log reported "unclean shutdown" happened. So, is a reset happened during commit operation?
Regards,
Aananth
Sent from my mobile phone
> On 13 மே, 2016, at 7:24 பிற்பகல், Richard Weinberger <richard@nod.at> wrote:
>
>> Am 13.05.2016 um 11:40 schrieb DHANAPAL, GNANACHANDRAN (G.):
>> Richard,
>>
>> I believe CRC value for a node is calculated in RAM before writing the node in NAND.
>> In this case, node CRC and calculated CRC are matching. so Will there be possibility
>> for corrupting key type area (32 bits) and keeping others intacted. or any other
>> possibility for node getting corrupted.
>
> I have to correct myself, the branches of an index node are covered by
> the node header CRC.
> This makes the whole picture more strange.
>
> You said you're facing the same issue on another unit.
> Is the corruption really the same? Bad key type 5?
>
> Thanks,
> //richard
^ permalink raw reply [flat|nested] 15+ messages in thread
end of thread, other threads:[~2016-05-13 16:03 UTC | newest]
Thread overview: 15+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2016-05-10 12:14 UBIFS Index Node Corruption - Invalid Key Type DHANAPAL, GNANACHANDRAN (G.)
2016-05-10 13:58 ` Richard Weinberger
2016-05-10 14:49 ` DHANAPAL, GNANACHANDRAN (G.)
2016-05-10 16:23 ` Richard Weinberger
2016-05-10 16:48 ` Richard Weinberger
[not found] ` <20160511065223.GA22220@visteon-gnana>
2016-05-11 7:29 ` DHANAPAL, GNANACHANDRAN (G.)
2016-05-11 9:22 ` Richard Weinberger
2016-05-11 11:16 ` DHANAPAL, GNANACHANDRAN (G.)
2016-05-11 12:42 ` Richard Weinberger
2016-05-11 14:47 ` Richard Weinberger
2016-05-12 13:29 ` Richard Weinberger
2016-05-13 9:40 ` DHANAPAL, GNANACHANDRAN (G.)
2016-05-13 13:54 ` Richard Weinberger
2016-05-13 16:02 ` DHANAPAL, GNANACHANDRAN (G.)
2016-05-13 16:03 ` CN, Aananth (A.A.)
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.