JFFS2 OOPS in 2.6.20

JFFS2 OOPS in 2.6.20

[Joakim Tjernlund]

Got a board with that has been powercycle tested while writing to JFFS2
FS with the following OOPS:
IP-Config: Complete:
      device=eth1, addr=192.168.101.172, mask=255.255.255.0,
gw=192.168.101.1,
     host=L_172_Node, domain=, nis-domain=(none),
     bootserver=192.168.1.63, rootserver=192.168.1.63, rootpath=
eth0: PHY is Generic MII (ffffffff)
------------[ cut here ]------------
Kernel BUG at c00d0a38 [verbose debug info unavailable]
Oops: Exception in kernel mode, sig: 5 [#1]

NIP: C00D0A38 LR: C00D09F8 CTR: 00000000
REGS: cfe8bd60 TRAP: 0700   Not tainted  (2.6.20)
MSR: 00029032 <EE,ME,IR,DR>  CR: 28028048  XER: 20000000
TASK = cff107f0[137] 'jffs2_gcd_mtd6' THREAD: cfe8a000
GPR00: 00000001 CFE8BE10 CFF107F0 00000000 C07EA6C8 00000000 00000000
00000000 
GPR08: C01CF678 01383E70 00000000 00000000 28028084 FC038F43 CFE8BE38
CFE8BE2C 
GPR16: CFE8BE38 C01D0000 00000000 C0733E70 CFE8BE24 CFE8BE20 CFF29A0C
00000000 
GPR24: 00000754 CFE8BEA0 CFF29A00 CFF48000 C0733E88 00000001 C07EA6C0
00000000 
NIP [C00D0A38] jffs2_do_read_inode_internal+0x134/0xfe8
LR [C00D09F8] jffs2_do_read_inode_internal+0xf4/0xfe8
Call Trace:
[CFE8BE10] [C00D09D4] jffs2_do_read_inode_internal+0xd0/0xfe8
(unreliable)
[CFE8BE90] [C00D1944] jffs2_do_crccheck_inode+0x58/0xb4
[CFE8BF00] [C00D58C8] jffs2_garbage_collect_pass+0x174/0x6c4
[CFE8BF50] [C00D70F4] jffs2_garbage_collect_thread+0xa0/0x11c
[CFE8BFF0] [C000FF70] kernel_thread+0x44/0x60
Instruction dump:
38000000 6000e001 7f860000 419e03ec 38000000 6000e002 7f860000 419e05f0 
813c0004 71200003 7c000026 54001ffe <0f000000> 60c92000 b13e0002
a0de0002 
 VFS: Mounted root (jffs2 filesystem).
Freeing unused kernel memory: 128k init

If someone can make an guess whats wrong, I would be a happy man

 Jocke

Re: JFFS2 OOPS in 2.6.20

[Joakim Tjernlund]

On Thu, 2007-03-08 at 18:14 +0100, Joakim Tjernlund wrote:
> Got a board with that has been powercycle tested while writing to JFFS2
> FS with the following OOPS:
> IP-Config: Complete:
>       device=eth1, addr=192.168.101.172, mask=255.255.255.0,
> gw=192.168.101.1,
>      host=L_172_Node, domain=, nis-domain=(none),
>      bootserver=192.168.1.63, rootserver=192.168.1.63, rootpath=
> eth0: PHY is Generic MII (ffffffff)
> ------------[ cut here ]------------
> Kernel BUG at c00d0a38 [verbose debug info unavailable]
> Oops: Exception in kernel mode, sig: 5 [#1]
> 
> NIP: C00D0A38 LR: C00D09F8 CTR: 00000000
> REGS: cfe8bd60 TRAP: 0700   Not tainted  (2.6.20)
> MSR: 00029032 <EE,ME,IR,DR>  CR: 28028048  XER: 20000000
> TASK = cff107f0[137] 'jffs2_gcd_mtd6' THREAD: cfe8a000
> GPR00: 00000001 CFE8BE10 CFF107F0 00000000 C07EA6C8 00000000 00000000
> 00000000 
> GPR08: C01CF678 01383E70 00000000 00000000 28028084 FC038F43 CFE8BE38
> CFE8BE2C 
> GPR16: CFE8BE38 C01D0000 00000000 C0733E70 CFE8BE24 CFE8BE20 CFF29A0C
> 00000000 
> GPR24: 00000754 CFE8BEA0 CFF29A00 CFF48000 C0733E88 00000001 C07EA6C0
> 00000000 
> NIP [C00D0A38] jffs2_do_read_inode_internal+0x134/0xfe8
> LR [C00D09F8] jffs2_do_read_inode_internal+0xf4/0xfe8
> Call Trace:
> [CFE8BE10] [C00D09D4] jffs2_do_read_inode_internal+0xd0/0xfe8
> (unreliable)
> [CFE8BE90] [C00D1944] jffs2_do_crccheck_inode+0x58/0xb4
> [CFE8BF00] [C00D58C8] jffs2_garbage_collect_pass+0x174/0x6c4
> [CFE8BF50] [C00D70F4] jffs2_garbage_collect_thread+0xa0/0x11c
> [CFE8BFF0] [C000FF70] kernel_thread+0x44/0x60
> Instruction dump:
> 38000000 6000e001 7f860000 419e03ec 38000000 6000e002 7f860000 419e05f0 
> 813c0004 71200003 7c000026 54001ffe <0f000000> 60c92000 b13e0002
> a0de0002 
>  VFS: Mounted root (jffs2 filesystem).
> Freeing unused kernel memory: 128k init
> 
> If someone can make an guess whats wrong, I would be a happy man
> 
>  Jocke

Adding verbose BUG reporting I see that this happens in 
fs/jffs2/readinode.c:376!
which looks:
static inline int read_unknown(struct jffs2_sb_info *c, struct jffs2_raw_node_ref *ref, struct jffs2_unknown_node *un)
{
	/* We don't mark unknown nodes as REF_UNCHECKED */
	BUG_ON(ref_flags(ref) == REF_UNCHECKED);

Re: JFFS2 OOPS in 2.6.20

[Joakim Tjernlund]

On Thu, 2007-03-08 at 18:33 +0100, Joakim Tjernlund wrote:
> On Thu, 2007-03-08 at 18:14 +0100, Joakim Tjernlund wrote:
> > Got a board with that has been powercycle tested while writing to JFFS2
> > FS with the following OOPS:
> > IP-Config: Complete:
> >       device=eth1, addr=192.168.101.172, mask=255.255.255.0,
> > gw=192.168.101.1,
> >      host=L_172_Node, domain=, nis-domain=(none),
> >      bootserver=192.168.1.63, rootserver=192.168.1.63, rootpath=
> > eth0: PHY is Generic MII (ffffffff)
> > ------------[ cut here ]------------
> > Kernel BUG at c00d0a38 [verbose debug info unavailable]
> > Oops: Exception in kernel mode, sig: 5 [#1]
> > 
> > NIP: C00D0A38 LR: C00D09F8 CTR: 00000000
> > REGS: cfe8bd60 TRAP: 0700   Not tainted  (2.6.20)
> > MSR: 00029032 <EE,ME,IR,DR>  CR: 28028048  XER: 20000000
> > TASK = cff107f0[137] 'jffs2_gcd_mtd6' THREAD: cfe8a000
> > GPR00: 00000001 CFE8BE10 CFF107F0 00000000 C07EA6C8 00000000 00000000
> > 00000000 
> > GPR08: C01CF678 01383E70 00000000 00000000 28028084 FC038F43 CFE8BE38
> > CFE8BE2C 
> > GPR16: CFE8BE38 C01D0000 00000000 C0733E70 CFE8BE24 CFE8BE20 CFF29A0C
> > 00000000 
> > GPR24: 00000754 CFE8BEA0 CFF29A00 CFF48000 C0733E88 00000001 C07EA6C0
> > 00000000 
> > NIP [C00D0A38] jffs2_do_read_inode_internal+0x134/0xfe8
> > LR [C00D09F8] jffs2_do_read_inode_internal+0xf4/0xfe8
> > Call Trace:
> > [CFE8BE10] [C00D09D4] jffs2_do_read_inode_internal+0xd0/0xfe8
> > (unreliable)
> > [CFE8BE90] [C00D1944] jffs2_do_crccheck_inode+0x58/0xb4
> > [CFE8BF00] [C00D58C8] jffs2_garbage_collect_pass+0x174/0x6c4
> > [CFE8BF50] [C00D70F4] jffs2_garbage_collect_thread+0xa0/0x11c
> > [CFE8BFF0] [C000FF70] kernel_thread+0x44/0x60
> > Instruction dump:
> > 38000000 6000e001 7f860000 419e03ec 38000000 6000e002 7f860000 419e05f0 
> > 813c0004 71200003 7c000026 54001ffe <0f000000> 60c92000 b13e0002
> > a0de0002 
> >  VFS: Mounted root (jffs2 filesystem).
> > Freeing unused kernel memory: 128k init
> > 
> > If someone can make an guess whats wrong, I would be a happy man
> > 
> >  Jocke
> 
> Adding verbose BUG reporting I see that this happens in 
> fs/jffs2/readinode.c:376!
> which looks:
> static inline int read_unknown(struct jffs2_sb_info *c, struct jffs2_raw_node_ref *ref, struct jffs2_unknown_node *un)
> {
> 	/* We don't mark unknown nodes as REF_UNCHECKED */
> 	BUG_ON(ref_flags(ref) == REF_UNCHECKED);
> 

Got another board too that has an identical OOPS, but prints 
JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa87a0. 
{0040,4001,00000044,00000000}
Just before the OOPS, here is the full OOPS:
JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa87a0. 
{0040,4001,00000044,00000000}
------------[ cut here ]------------
kernel BUG at fs/jffs2/readinode.c:376!
Oops: Exception in kernel mode, sig: 5 [#1]

NIP: C00D0A38 LR: C00D09F8 CTR: 00000000
REGS: cfec7d60 TRAP: 0700   Not tainted  (2.6.20)
MSR: 00029032 <EE,ME,IR,DR>  CR: 24028048  XER: 20000000
TASK = cff0db80[137] 'jffs2_gcd_mtd6' THREAD: cfec6000
GPR00: 00000001 CFEC7E10 CFF0DB80 00000000 C07EA6C8 00000000 00000000 00000000 
GPR08: C01CF678 03AA6C6C 00000000 00000000 24028084 C0A89688 CFEC7E38 CFEC7E2C 
GPR16: CFEC7E38 C01D0000 00000000 CFE24C24 CFEC7E24 CFEC7E20 CFF28A0C 00000000 
GPR24: 000009B0 CFEC7EA0 CFF28A00 CFF48000 CFE24C3C 00000001 C07EA6C0 00000000 
NIP [C00D0A38] jffs2_do_read_inode_internal+0x134/0xfe8
LR [C00D09F8] jffs2_do_read_inode_internal+0xf4/0xfe8
Call Trace:
[CFEC7E10] [C00D09D4] jffs2_do_read_inode_internal+0xd0/0xfe8 (unreliable)
[CFEC7E90] [C00D1944] jffs2_do_crccheck_inode+0x58/0xb4
[CFEC7F00] [C00D58C8] jffs2_garbage_collect_pass+0x174/0x6c4
[CFEC7F50] [C00D70F4] jffs2_garbage_collect_thread+0xa0/0x11c
[CFEC7FF0] [C000FF70] kernel_thread+0x44/0x60
Instruction dump:
38000000 6000e001 7f860000 419e03ec 38000000 6000e002 7f860000 419e05f0 
813c0004 71200003 7c000026 54001ffe <0f000000> 60c92000 b13e0002 a0de0002 
 VFS: Mounted root (jffs2 filesystem).
Freeing unused kernel memory: 128k init

Re: JFFS2 OOPS in 2.6.20

[David Woodhouse]

On Thu, 2007-03-08 at 18:44 +0100, Joakim Tjernlund wrote:
> Got another board too that has an identical OOPS, but prints 
> JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa87a0. 
> {0040,4001,00000044,00000000}
> Just before the OOPS, here is the full OOPS:
> JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa87a0. 
> {0040,4001,00000044,00000000}
> ------------[ cut here ]------------
> kernel BUG at fs/jffs2/readinode.c:376! 

Can you make it print the flash offset of the offending node, and the
header contents (like the 0040,4001,00000044,00000000 above) before
dying? Then reproduce with CONFIG_JFFS2_FS_DEBUG=1 and show me the full
output.

-- 
dwmw2

Re: JFFS2 OOPS in 2.6.20

[Artem Bityutskiy]

On Thu, 2007-03-08 at 18:37 +0000, David Woodhouse wrote:
> Then reproduce with CONFIG_JFFS2_FS_DEBUG=1 and show me the full
> output.

/me is trying to recall ho many times he have heard this part :-) I need
to add a FAQ entry for this, since you do not seem to be like doing
this :-)

-- 
Best regards,
Artem Bityutskiy (Битюцкий Артём)

Re: JFFS2 OOPS in 2.6.20

[David Woodhouse]

On Thu, 2007-03-08 at 18:37 +0000, David Woodhouse wrote:
> Can you make it print the flash offset of the offending node, and the
> header contents (like the 0040,4001,00000044,00000000 above) before
> dying? Then reproduce with CONFIG_JFFS2_FS_DEBUG=1 and show me the
> full output.

We've seen something very similar to this before.

http://lists.infradead.org/pipermail/linux-mtd/2006-June/015878.html
http://git.infradead.org/?p=mtd-2.6.git;a=commitdiff;h=3877f0b6c9f54d43e55e532404a935b90393b635

-- 
dwmw2

Re: JFFS2 OOPS in 2.6.20

[Joakim Tjernlund]

On Thu, 2007-03-08 at 18:37 +0000, David Woodhouse wrote:
> On Thu, 2007-03-08 at 18:44 +0100, Joakim Tjernlund wrote:
> > Got another board too that has an identical OOPS, but prints 
> > JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa87a0. 
> > {0040,4001,00000044,00000000}
> > Just before the OOPS, here is the full OOPS:
> > JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa87a0. 
> > {0040,4001,00000044,00000000}
> > ------------[ cut here ]------------
> > kernel BUG at fs/jffs2/readinode.c:376! 
> 
> Can you make it print the flash offset of the offending node, and the
> header contents (like the 0040,4001,00000044,00000000 above) before
> dying? Then reproduce with CONFIG_JFFS2_FS_DEBUG=1 and show me the full
> output.
> 

Added this:
static inline int read_unknown(struct jffs2_sb_info *c, struct jffs2_raw_node_ref *ref, struct jffs2_unknown_node *un)
{
+	if (ref_flags(ref) == REF_UNCHECKED) {
+		JFFS2_NOTICE(" ref_flags(ref) == REF_UNCHECKED at %#08x. {%04x,%04x,%08x,%08x}\n",
+			     ref_offset(ref), je16_to_cpu(un->magic),
+			     je16_to_cpu(un->nodetype),
+			     je32_to_cpu(un->totlen),
+			     je32_to_cpu(un->hdr_crc));
+	}
	/* We don't mark unknown nodes as REF_UNCHECKED */
	BUG_ON(ref_flags(ref) == REF_UNCHECKED);
and CONFIG_JFFS2_FS_DEBUG=1

Got this trace:
JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa87a0. 
{0040,4001,00000044,00000000}
JFFS2 error: (137) __jffs2_dbg_dump_node: wrong common header CRC.
JFFS2 notice: (137) read_unknown:  ref_flags(ref) == REF_UNCHECKED at 0x3aa6c6c.
 {0000,0000,00000000,00000000}
------------[ cut here ]------------
kernel BUG at fs/jffs2/readinode.c:383!
Oops: Exception in kernel mode, sig: 5 [#1]

NIP: C00D149C LR: C00D1670 CTR: C00FAB00
REGS: cfec7d50 TRAP: 0700   Not tainted  (2.6.20)
MSR: 00029032 <EE,ME,IR,DR>  CR: 22028022  XER: 00000000
TASK = cff32090[137] 'jffs2_gcd_mtd6' THREAD: cfec6000
GPR00: 00000001 CFEC7E00 CFF32090 00000072 0210EBCC FFFFFFFF C0113E14 C024211C 
GPR08: 00000000 00000000 00000000 C0240000 22028042 C0A89688 C01D0000 C01D0000 
GPR16: C01D0000 00000000 C01D0000 CFE2BC24 CFEC7E14 CFEC7E10 CFF66A0C 00000000 
GPR24: 000009B0 CFEC7EA0 CFF66A00 CFF13000 CFE2BC3C 00000001 00000000 C07EA6C0 
NIP [C00D149C] jffs2_do_read_inode_internal+0x1a0/0x1198
LR [C00D1670] jffs2_do_read_inode_internal+0x374/0x1198
Call Trace:
[CFEC7E00] [C00D1670] jffs2_do_read_inode_internal+0x374/0x1198 (unreliable)
[CFEC7E90] [C00D24EC] jffs2_do_crccheck_inode+0x58/0xb4
[CFEC7F00] [C00D6BD4] jffs2_garbage_collect_pass+0x1a8/0x880
[CFEC7F50] [C00D89A8] jffs2_garbage_collect_thread+0xa8/0x178
[CFEC7FF0] [C000FF70] kernel_thread+0x44/0x60
Instruction dump:
7f880000 419e04b0 38000000 6000e002 7f880000 419e06b0 801c0004 70090003 
418201c4 70090003 7c000026 54001ffe <0f000000> 61092000 b13f0002 a11f0002 
 VFS: Mounted root (jffs2 filesystem).
Freeing unused kernel memory: 128k init
jffs2_lookup()
jffs2_read_inode(): inode->i_ino == 3
[JFFS2 DBG] (1) jffs2_do_read_inode: read inode #3
[JFFS2 DBG] (1) jffs2_do_read_inode_internal: ino #3 nlink is 1
[JFFS2 DBG] (1) jffs2_get_inode_nodes: ino #3

[SNIP] alot of output

 Jocke

Re: JFFS2 OOPS in 2.6.20

[David Woodhouse]

On Fri, 2007-03-09 at 10:02 +0100, Joakim Tjernlund wrote:
> JFFS2 notice: (137) read_unknown:  ref_flags(ref) == REF_UNCHECKED at 0x3aa6c6c.
>  {0000,0000,00000000,00000000} 

Ouch. That CRC is actually "correct". It's why we should have used
crc32(-1, buf, len) instead of crc32(0, buf, len) from the start.

Do you have any idea how you managed to get those zeroes on the flash?

diff --git a/fs/jffs2/readinode.c b/fs/jffs2/readinode.c
index 58a0b91..ef6522e 100644
--- a/fs/jffs2/readinode.c
+++ b/fs/jffs2/readinode.c
@@ -373,7 +373,14 @@ free_out:
 static inline int read_unknown(struct jffs2_sb_info *c, struct jffs2_raw_node_ref *ref, struct jffs2_unknown_node *un)
 {
 	/* We don't mark unknown nodes as REF_UNCHECKED */
-	BUG_ON(ref_flags(ref) == REF_UNCHECKED);
+	if (ref_flags(ref) == REF_UNCHECKED) {
+		JFFS2_ERROR("REF_UNCHECKED but unknown node at %#08x\n",
+			    ref_offset(ref));
+		JFFS2_ERROR("Node is {%04x,%04x,%08x,%08x}. Please report this error.\n",
+                            je16_to_cpu(un->magic), je16_to_cpu(un->nodetype),
+                            je32_to_cpu(un->totlen), je32_to_cpu(un->hdr_crc));
+		return 1;
+	}
 
 	un->nodetype = cpu_to_je16(JFFS2_NODE_ACCURATE | je16_to_cpu(un->nodetype));
 
@@ -576,6 +583,13 @@ static int jffs2_get_inode_nodes(struct jffs2_sb_info *c, struct jffs2_inode_inf
 			jffs2_mark_node_obsolete(c, ref);
 			goto cont;
 		}
+		/* Due to poor choice of crc32 seed, an all-zero node will have a correct CRC */
+		if (!je32_to_cpu(node->u.hdr_crc) && !je16_to_cpu(node->u.nodetype) &&
+		    !je16_to_cpu(node->u.magic) && je32_to_cpu(node->u.totlen)) {
+			JFFS2_NOTICE("All zero node header at %#08x.\n", ref_offset(ref));
+			jffs2_mark_node_obsolete(c, ref);
+			goto cont;
+		}
 
 		switch (je16_to_cpu(node->u.nodetype)) {
 
diff --git a/fs/jffs2/scan.c b/fs/jffs2/scan.c
index 31c1475..e482081 100644
--- a/fs/jffs2/scan.c
+++ b/fs/jffs2/scan.c
@@ -734,6 +734,16 @@ scan_more:
 			ofs += 4;
 			continue;
 		}
+		/* Due to poor choice of crc32 seed, an all-zero node will have a correct CRC */
+		if (!je32_to_cpu(node->hdr_crc) && !je16_to_cpu(node->nodetype) &&
+		    !je16_to_cpu(node->magic) && je32_to_cpu(node->totlen)) {
+			noisy_printk(&noise, "jffs2_scan_eraseblock(): All zero node header at 0x%08x.\n", ofs);
+		       
+			if ((err = jffs2_scan_dirty_space(c, jeb, 4)))
+				return err;
+			ofs += 4;
+			continue;
+		}
 
 		if (ofs + je32_to_cpu(node->totlen) >
 		    jeb->offset + c->sector_size) {

-- 
dwmw2

Re: JFFS2 OOPS in 2.6.20

[Joakim Tjernlund]

On Fri, 2007-03-09 at 09:23 +0000, David Woodhouse wrote:
> On Fri, 2007-03-09 at 10:02 +0100, Joakim Tjernlund wrote:
> > JFFS2 notice: (137) read_unknown:  ref_flags(ref) == REF_UNCHECKED at 0x3aa6c6c.
> >  {0000,0000,00000000,00000000} 
> 
> Ouch. That CRC is actually "correct". It's why we should have used
> crc32(-1, buf, len) instead of crc32(0, buf, len) from the start.
> 
> Do you have any idea how you managed to get those zeroes on the flash?

Not much, our system test did power cycle testing while doing SW
upgrade(lots of writing of files).

Tested your patch and now it boots again with this :)
JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa87a0. 
{0040,4001,00000044,00000000}
JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa6c6c
JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa517c. 
{0400,4001,00000000,00000004}
JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa28fc
JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa1ef8. 
{0000,0000,00000000,00100400}
JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa1438. 
{0000,4000,00000000,00000000}
JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa0a44
JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa3e84
JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa3d80. 
{0040,4000,00000000,01000005}
JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa33c8
JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
VFS: Mounted root (jffs2 filesystem).

 Jocke

Re: JFFS2 OOPS in 2.6.20

[David Woodhouse]

On Fri, 2007-03-09 at 11:46 +0100, Joakim Tjernlund wrote:
> Tested your patch and now it boots again with this :) 
> JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa28fc
> JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.

Stupid dwmw2. No biscuit.

diff -u b/fs/jffs2/readinode.c b/fs/jffs2/readinode.c
--- b/fs/jffs2/readinode.c
+++ b/fs/jffs2/readinode.c
@@ -585,7 +585,7 @@
 		}
 		/* Due to poor choice of crc32 seed, an all-zero node will have a correct CRC */
 		if (!je32_to_cpu(node->u.hdr_crc) && !je16_to_cpu(node->u.nodetype) &&
-		    !je16_to_cpu(node->u.magic) && je32_to_cpu(node->u.totlen)) {
+		    !je16_to_cpu(node->u.magic) && !je32_to_cpu(node->u.totlen)) {
 			JFFS2_NOTICE("All zero node header at %#08x.\n", ref_offset(ref));
 			jffs2_mark_node_obsolete(c, ref);
 			goto cont;
diff -u b/fs/jffs2/scan.c b/fs/jffs2/scan.c
--- b/fs/jffs2/scan.c
+++ b/fs/jffs2/scan.c
@@ -736,7 +736,7 @@
 		}
 		/* Due to poor choice of crc32 seed, an all-zero node will have a correct CRC */
 		if (!je32_to_cpu(node->hdr_crc) && !je16_to_cpu(node->nodetype) &&
-		    !je16_to_cpu(node->magic) && je32_to_cpu(node->totlen)) {
+		    !je16_to_cpu(node->magic) && !je32_to_cpu(node->totlen)) {
 			noisy_printk(&noise, "jffs2_scan_eraseblock(): All zero node header at 0x%08x.\n", ofs);
 		       
 			if ((err = jffs2_scan_dirty_space(c, jeb, 4)))

-- 
dwmw2

Re: JFFS2 OOPS in 2.6.20

[Joakim Tjernlund]

On Fri, 2007-03-09 at 11:46 +0100, Joakim Tjernlund wrote:
> On Fri, 2007-03-09 at 09:23 +0000, David Woodhouse wrote:
> > On Fri, 2007-03-09 at 10:02 +0100, Joakim Tjernlund wrote:
> > > JFFS2 notice: (137) read_unknown:  ref_flags(ref) == REF_UNCHECKED at 0x3aa6c6c.
> > >  {0000,0000,00000000,00000000} 
> > 
> > Ouch. That CRC is actually "correct". It's why we should have used
> > crc32(-1, buf, len) instead of crc32(0, buf, len) from the start.
> > 
> > Do you have any idea how you managed to get those zeroes on the flash?
> 
> Not much, our system test did power cycle testing while doing SW
> upgrade(lots of writing of files).
> 
> Tested your patch and now it boots again with this :)
> JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa87a0. 
> {0040,4001,00000044,00000000}
> JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa6c6c
> JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
> JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa517c. 
> {0400,4001,00000000,00000004}
> JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa28fc
> JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
> JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa1ef8. 
> {0000,0000,00000000,00100400}
> JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa1438. 
> {0000,4000,00000000,00000000}
> JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa0a44
> JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
> JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa3e84
> JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
> JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa3d80. 
> {0040,4000,00000000,01000005}
> JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa33c8
> JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
> VFS: Mounted root (jffs2 filesystem).

This does not look right, none of the "All zero node header" checks has triggered.

hmm,
je32_to_cpu(node->u.totlen) should be !je32_to_cpu(node->u.totlen)

also I think this check should be before the real crc32 check.
After that I get:
JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa87a0. 
{0040,4001,00000044,00000000}
JFFS2 notice: (137) jffs2_get_inode_nodes: All zero node header at 0x3aa6c6c.
JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa517c. 
{0400,4001,00000000,00000004}
JFFS2 notice: (137) jffs2_get_inode_nodes: All zero node header at 0x3aa28fc.
JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa1ef8. 
{0000,0000,00000000,00100400}
JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa1438. 
{0000,4000,00000000,00000000}
JFFS2 notice: (137) jffs2_get_inode_nodes: All zero node header at 0x3aa0a44.
JFFS2 notice: (137) jffs2_get_inode_nodes: All zero node header at 0x3aa3e84.
JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa3d80. 
{0040,4000,00000000,01000005}
JFFS2 notice: (137) jffs2_get_inode_nodes: All zero node header at 0x3aa33c8.
VFS: Mounted root (jffs2 filesystem).


diff --git a/fs/jffs2/readinode.c b/fs/jffs2/readinode.c
index 58a0b91..7f7618c 100644
--- a/fs/jffs2/readinode.c
+++ b/fs/jffs2/readinode.c
@@ -373,7 +373,14 @@ free_out:
 static inline int read_unknown(struct jffs2_sb_info *c, struct jffs2_raw_node_ref *ref, struct jffs2_unknown_node *un)
 {
 	/* We don't mark unknown nodes as REF_UNCHECKED */
-	BUG_ON(ref_flags(ref) == REF_UNCHECKED);
+	if (ref_flags(ref) == REF_UNCHECKED) {
+		JFFS2_ERROR("REF_UNCHECKED but unknown node at %#08x\n",
+			    ref_offset(ref));
+		JFFS2_ERROR("Node is {%04x,%04x,%08x,%08x}. Please report this error.\n",
+                            je16_to_cpu(un->magic), je16_to_cpu(un->nodetype),
+                            je32_to_cpu(un->totlen), je32_to_cpu(un->hdr_crc));
+		return 1;
+	}
 
 	un->nodetype = cpu_to_je16(JFFS2_NODE_ACCURATE | je16_to_cpu(un->nodetype));
 
@@ -565,6 +572,14 @@ static int jffs2_get_inode_nodes(struct jffs2_sb_info *c, struct jffs2_inode_inf
 
 		node = (union jffs2_node_union *)bufstart;
 
+		/* Due to poor choice of crc32 seed, an all-zero node will have a correct CRC */
+		if (!je32_to_cpu(node->u.hdr_crc) && !je16_to_cpu(node->u.nodetype) &&
+		    !je16_to_cpu(node->u.magic) && !je32_to_cpu(node->u.totlen)) {
+			JFFS2_NOTICE("All zero node header at %#08x.\n", ref_offset(ref));
+			jffs2_mark_node_obsolete(c, ref);
+			goto cont;
+		}
+
 		/* No need to mask in the valid bit; it shouldn't be invalid */
 		if (je32_to_cpu(node->u.hdr_crc) != crc32(0, node, sizeof(node->u)-4)) {
 			JFFS2_NOTICE("Node header CRC failed at %#08x. {%04x,%04x,%08x,%08x}\n",
diff --git a/fs/jffs2/scan.c b/fs/jffs2/scan.c
index 3af746e..b98661a 100644
--- a/fs/jffs2/scan.c
+++ b/fs/jffs2/scan.c
@@ -718,6 +718,17 @@ scan_more:
 		crcnode.totlen = node->totlen;
 		hdr_crc = crc32(0, &crcnode, sizeof(crcnode)-4);
 
+		/* Due to poor choice of crc32 seed, an all-zero node will have a correct CRC */
+		if (!je32_to_cpu(node->hdr_crc) && !je16_to_cpu(node->nodetype) &&
+		    !je16_to_cpu(node->magic) && !je32_to_cpu(node->totlen)) {
+			noisy_printk(&noise, "jffs2_scan_eraseblock(): All zero node header at 0x%08x.\n", ofs);
+		       
+			if ((err = jffs2_scan_dirty_space(c, jeb, 4)))
+				return err;
+			ofs += 4;
+			continue;
+		}
+
 		if (hdr_crc != je32_to_cpu(node->hdr_crc)) {
 			noisy_printk(&noise, "jffs2_scan_eraseblock(): Node at 0x%08x {0x%04x, 0x%04x, 0x%08x) has invalid CRC 0x%08x (calculated 0x%08x)\n",
 				     ofs, je16_to_cpu(node->magic),

Re: JFFS2 OOPS in 2.6.20

[David Woodhouse]

On Fri, 2007-03-09 at 12:15 +0100, Joakim Tjernlund wrote:
> also I think this check should be before the real crc32 check. 

Does it matter? It's hardly a fast path :)

-- 
dwmw2

Re: JFFS2 OOPS in 2.6.20

[Joakim Tjernlund]

On Fri, 2007-03-09 at 11:24 +0000, David Woodhouse wrote:
> On Fri, 2007-03-09 at 12:15 +0100, Joakim Tjernlund wrote:
> > also I think this check should be before the real crc32 check. 
> 
> Does it matter? It's hardly a fast path :)

not really, I was thinking about soemthing else and I was wrong.

 Jocke

Re: JFFS2 OOPS in 2.6.20

[Joakim Tjernlund]

On Fri, 2007-03-09 at 12:15 +0100, Joakim Tjernlund wrote:
> On Fri, 2007-03-09 at 11:46 +0100, Joakim Tjernlund wrote:
> > On Fri, 2007-03-09 at 09:23 +0000, David Woodhouse wrote:
> > > On Fri, 2007-03-09 at 10:02 +0100, Joakim Tjernlund wrote:
> > > > JFFS2 notice: (137) read_unknown:  ref_flags(ref) == REF_UNCHECKED at 0x3aa6c6c.
> > > >  {0000,0000,00000000,00000000} 
> > > 
> > > Ouch. That CRC is actually "correct". It's why we should have used
> > > crc32(-1, buf, len) instead of crc32(0, buf, len) from the start.
> > > 
> > > Do you have any idea how you managed to get those zeroes on the flash?
> > 
> > Not much, our system test did power cycle testing while doing SW
> > upgrade(lots of writing of files).
> > 
> > Tested your patch and now it boots again with this :)
> > JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa87a0. 
> > {0040,4001,00000044,00000000}
> > JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa6c6c
> > JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
> > JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa517c. 
> > {0400,4001,00000000,00000004}
> > JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa28fc
> > JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
> > JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa1ef8. 
> > {0000,0000,00000000,00100400}
> > JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa1438. 
> > {0000,4000,00000000,00000000}
> > JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa0a44
> > JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
> > JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa3e84
> > JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
> > JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa3d80. 
> > {0040,4000,00000000,01000005}
> > JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa33c8
> > JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
> > VFS: Mounted root (jffs2 filesystem).
> 
> This does not look right, none of the "All zero node header" checks has triggered.
> 
> hmm,
> je32_to_cpu(node->u.totlen) should be !je32_to_cpu(node->u.totlen)
> 
> also I think this check should be before the real crc32 check.
> After that I get:
> JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa87a0. 
> {0040,4001,00000044,00000000}
> JFFS2 notice: (137) jffs2_get_inode_nodes: All zero node header at 0x3aa6c6c.
> JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa517c. 
> {0400,4001,00000000,00000004}
> JFFS2 notice: (137) jffs2_get_inode_nodes: All zero node header at 0x3aa28fc.
> JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa1ef8. 
> {0000,0000,00000000,00100400}
> JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa1438. 
> {0000,4000,00000000,00000000}
> JFFS2 notice: (137) jffs2_get_inode_nodes: All zero node header at 0x3aa0a44.
> JFFS2 notice: (137) jffs2_get_inode_nodes: All zero node header at 0x3aa3e84.
> JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa3d80. 
> {0040,4000,00000000,01000005}
> JFFS2 notice: (137) jffs2_get_inode_nodes: All zero node header at 0x3aa33c8.
> VFS: Mounted root (jffs2 filesystem).
> 

The check in scan is rendundant. You will never reach it due to two
earlier checks:
	if (je16_to_cpu(node->magic) != JFFS2_MAGIC_BITMASK) {
and
	crcnode.nodetype = cpu_to_je16( je16_to_cpu(node->nodetype) | JFFS2_NODE_ACCURATE);

I wonder if JFFS2_NODE_ACCURATE mask bit could be used in readinode.c as well?

 Jocke

Re: JFFS2 OOPS in 2.6.20

[Joakim Tjernlund]

On Fri, 2007-03-09 at 14:54 +0100, Joakim Tjernlund wrote:
> On Fri, 2007-03-09 at 12:15 +0100, Joakim Tjernlund wrote:
> > On Fri, 2007-03-09 at 11:46 +0100, Joakim Tjernlund wrote:
> > > On Fri, 2007-03-09 at 09:23 +0000, David Woodhouse wrote:
> > > > On Fri, 2007-03-09 at 10:02 +0100, Joakim Tjernlund wrote:
> > > > > JFFS2 notice: (137) read_unknown:  ref_flags(ref) == REF_UNCHECKED at 0x3aa6c6c.
> > > > >  {0000,0000,00000000,00000000} 
> > > > 
> > > > Ouch. That CRC is actually "correct". It's why we should have used
> > > > crc32(-1, buf, len) instead of crc32(0, buf, len) from the start.
> > > > 
> > > > Do you have any idea how you managed to get those zeroes on the flash?
> > > 
> > > Not much, our system test did power cycle testing while doing SW
> > > upgrade(lots of writing of files).
> > > 
> > > Tested your patch and now it boots again with this :)
> > > JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa87a0. 
> > > {0040,4001,00000044,00000000}
> > > JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa6c6c
> > > JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
> > > JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa517c. 
> > > {0400,4001,00000000,00000004}
> > > JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa28fc
> > > JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
> > > JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa1ef8. 
> > > {0000,0000,00000000,00100400}
> > > JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa1438. 
> > > {0000,4000,00000000,00000000}
> > > JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa0a44
> > > JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
> > > JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa3e84
> > > JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
> > > JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa3d80. 
> > > {0040,4000,00000000,01000005}
> > > JFFS2 error: (137) read_unknown: REF_UNCHECKED but unknown node at 0x3aa33c8
> > > JFFS2 error: (137) read_unknown: Node is {0000,0000,00000000,00000000}. Please report this error.
> > > VFS: Mounted root (jffs2 filesystem).
> > 
> > This does not look right, none of the "All zero node header" checks has triggered.
> > 
> > hmm,
> > je32_to_cpu(node->u.totlen) should be !je32_to_cpu(node->u.totlen)
> > 
> > also I think this check should be before the real crc32 check.
> > After that I get:
> > JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa87a0. 
> > {0040,4001,00000044,00000000}
> > JFFS2 notice: (137) jffs2_get_inode_nodes: All zero node header at 0x3aa6c6c.
> > JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa517c. 
> > {0400,4001,00000000,00000004}
> > JFFS2 notice: (137) jffs2_get_inode_nodes: All zero node header at 0x3aa28fc.
> > JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa1ef8. 
> > {0000,0000,00000000,00100400}
> > JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa1438. 
> > {0000,4000,00000000,00000000}
> > JFFS2 notice: (137) jffs2_get_inode_nodes: All zero node header at 0x3aa0a44.
> > JFFS2 notice: (137) jffs2_get_inode_nodes: All zero node header at 0x3aa3e84.
> > JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa3d80. 
> > {0040,4000,00000000,01000005}
> > JFFS2 notice: (137) jffs2_get_inode_nodes: All zero node header at 0x3aa33c8.
> > VFS: Mounted root (jffs2 filesystem).
> > 
> 
> The check in scan is rendundant. You will never reach it due to two
> earlier checks:
> 	if (je16_to_cpu(node->magic) != JFFS2_MAGIC_BITMASK) {
> and
> 	crcnode.nodetype = cpu_to_je16( je16_to_cpu(node->nodetype) | JFFS2_NODE_ACCURATE);
> 
> I wonder if JFFS2_NODE_ACCURATE mask bit could be used in readinode.c as well?
> 
>  Jocke

probably better to remove the zero crc32 check and add a:
   if (je16_to_cpu(node->u.magic) != JFFS2_MAGIC_BITMASK)

to make sure it is a JFFS2 node with the added benefit that this will work
when ->point is added too.

 Jocke

Re: JFFS2 OOPS in 2.6.20

[Joakim Tjernlund]

> > 
> > The check in scan is rendundant. You will never reach it due to two
> > earlier checks:
> > 	if (je16_to_cpu(node->magic) != JFFS2_MAGIC_BITMASK) {
> > and
> > 	crcnode.nodetype = cpu_to_je16( je16_to_cpu(node->nodetype) | JFFS2_NODE_ACCURATE);
> > 
> > I wonder if JFFS2_NODE_ACCURATE mask bit could be used in readinode.c as well?
> > 
> >  Jocke
> 
> probably better to remove the zero crc32 check and add a:
>    if (je16_to_cpu(node->u.magic) != JFFS2_MAGIC_BITMASK)
> 
> to make sure it is a JFFS2 node with the added benefit that this will work
> when ->point is added too.
> 
>  Jocke

How about this fix instead:

>From 4421fa227585b205f52e90966683c0a57737547b Mon Sep 17 00:00:00 2001
From: Joakim Tjernlund <Joakim.Tjernlund@transmode.se>
Date: Sat, 10 Mar 2007 16:59:03 +0100
Subject: [PATCH] Better fix for all-zero node headers
No need to check for all-zero header since the header cannot
be zero due to other checks.
Replace the all-zero header check in readinode.c with a
check for the magic word.

Signed-off-by: Joakim Tjernlund <Joakim.Tjernlund@transmode.se>
---
 fs/jffs2/readinode.c |    8 ++++----
 fs/jffs2/scan.c      |   11 -----------
 2 files changed, 4 insertions(+), 15 deletions(-)

diff --git a/fs/jffs2/readinode.c b/fs/jffs2/readinode.c
index 7f7618c..9f6885b 100644
--- a/fs/jffs2/readinode.c
+++ b/fs/jffs2/readinode.c
@@ -572,10 +572,10 @@ static int jffs2_get_inode_nodes(struct jffs2_sb_info *c, struct jffs2_inode_inf
 
 		node = (union jffs2_node_union *)bufstart;
 
-		/* Due to poor choice of crc32 seed, an all-zero node will have a correct CRC */
-		if (!je32_to_cpu(node->u.hdr_crc) && !je16_to_cpu(node->u.nodetype) &&
-		    !je16_to_cpu(node->u.magic) && !je32_to_cpu(node->u.totlen)) {
-			JFFS2_NOTICE("All zero node header at %#08x.\n", ref_offset(ref));
+		if (je16_to_cpu(node->u.magic) != JFFS2_MAGIC_BITMASK) {
+			/* Not a JFFS2 node, whinge and move on */
+			JFFS2_NOTICE("Wrong magic bitmask 0x%04x in node header at %#08x.\n", je16_to_cpu(node->u.magic),
+				     ref_offset(ref));
 			jffs2_mark_node_obsolete(c, ref);
 			goto cont;
 		}
diff --git a/fs/jffs2/scan.c b/fs/jffs2/scan.c
index b98661a..3af746e 100644
--- a/fs/jffs2/scan.c
+++ b/fs/jffs2/scan.c
@@ -718,17 +718,6 @@ scan_more:
 		crcnode.totlen = node->totlen;
 		hdr_crc = crc32(0, &crcnode, sizeof(crcnode)-4);
 
-		/* Due to poor choice of crc32 seed, an all-zero node will have a correct CRC */
-		if (!je32_to_cpu(node->hdr_crc) && !je16_to_cpu(node->nodetype) &&
-		    !je16_to_cpu(node->magic) && !je32_to_cpu(node->totlen)) {
-			noisy_printk(&noise, "jffs2_scan_eraseblock(): All zero node header at 0x%08x.\n", ofs);
-		       
-			if ((err = jffs2_scan_dirty_space(c, jeb, 4)))
-				return err;
-			ofs += 4;
-			continue;
-		}
-
 		if (hdr_crc != je32_to_cpu(node->hdr_crc)) {
 			noisy_printk(&noise, "jffs2_scan_eraseblock(): Node at 0x%08x {0x%04x, 0x%04x, 0x%08x) has invalid CRC 0x%08x (calculated 0x%08x)\n",
 				     ofs, je16_to_cpu(node->magic),
-- 
1.4.4.4

Re: JFFS2 OOPS in 2.6.20

[Joakim Tjernlund]

On Fri, 2007-03-09 at 10:02 +0100, Joakim Tjernlund wrote:
> On Thu, 2007-03-08 at 18:37 +0000, David Woodhouse wrote:
> > On Thu, 2007-03-08 at 18:44 +0100, Joakim Tjernlund wrote:
> > > Got another board too that has an identical OOPS, but prints 
> > > JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa87a0. 
> > > {0040,4001,00000044,00000000}
> > > Just before the OOPS, here is the full OOPS:
> > > JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa87a0. 
> > > {0040,4001,00000044,00000000}
> > > ------------[ cut here ]------------
> > > kernel BUG at fs/jffs2/readinode.c:376! 
> > 
> > Can you make it print the flash offset of the offending node, and the
> > header contents (like the 0040,4001,00000044,00000000 above) before
> > dying? Then reproduce with CONFIG_JFFS2_FS_DEBUG=1 and show me the full
> > output.
> > 
> 
> Added this:
> static inline int read_unknown(struct jffs2_sb_info *c, struct jffs2_raw_node_ref *ref, struct jffs2_unknown_node *un)
> {
> +	if (ref_flags(ref) == REF_UNCHECKED) {
> +		JFFS2_NOTICE(" ref_flags(ref) == REF_UNCHECKED at %#08x. {%04x,%04x,%08x,%08x}\n",
> +			     ref_offset(ref), je16_to_cpu(un->magic),
> +			     je16_to_cpu(un->nodetype),
> +			     je32_to_cpu(un->totlen),
> +			     je32_to_cpu(un->hdr_crc));
> +	}
> 	/* We don't mark unknown nodes as REF_UNCHECKED */
> 	BUG_ON(ref_flags(ref) == REF_UNCHECKED);
> and CONFIG_JFFS2_FS_DEBUG=1
> 
> Got this trace:
> JFFS2 notice: (137) jffs2_get_inode_nodes: Node header CRC failed at 0x3aa87a0. 
> {0040,4001,00000044,00000000}
> JFFS2 error: (137) __jffs2_dbg_dump_node: wrong common header CRC.
> JFFS2 notice: (137) read_unknown:  ref_flags(ref) == REF_UNCHECKED at 0x3aa6c6c.
>  {0000,0000,00000000,00000000}
> ------------[ cut here ]------------
> kernel BUG at fs/jffs2/readinode.c:383!
> Oops: Exception in kernel mode, sig: 5 [#1]
> 
> NIP: C00D149C LR: C00D1670 CTR: C00FAB00
> REGS: cfec7d50 TRAP: 0700   Not tainted  (2.6.20)
> MSR: 00029032 <EE,ME,IR,DR>  CR: 22028022  XER: 00000000
> TASK = cff32090[137] 'jffs2_gcd_mtd6' THREAD: cfec6000
> GPR00: 00000001 CFEC7E00 CFF32090 00000072 0210EBCC FFFFFFFF C0113E14 C024211C 
> GPR08: 00000000 00000000 00000000 C0240000 22028042 C0A89688 C01D0000 C01D0000 
> GPR16: C01D0000 00000000 C01D0000 CFE2BC24 CFEC7E14 CFEC7E10 CFF66A0C 00000000 
> GPR24: 000009B0 CFEC7EA0 CFF66A00 CFF13000 CFE2BC3C 00000001 00000000 C07EA6C0 
> NIP [C00D149C] jffs2_do_read_inode_internal+0x1a0/0x1198
> LR [C00D1670] jffs2_do_read_inode_internal+0x374/0x1198
> Call Trace:
> [CFEC7E00] [C00D1670] jffs2_do_read_inode_internal+0x374/0x1198 (unreliable)
> [CFEC7E90] [C00D24EC] jffs2_do_crccheck_inode+0x58/0xb4
> [CFEC7F00] [C00D6BD4] jffs2_garbage_collect_pass+0x1a8/0x880
> [CFEC7F50] [C00D89A8] jffs2_garbage_collect_thread+0xa8/0x178
> [CFEC7FF0] [C000FF70] kernel_thread+0x44/0x60
> Instruction dump:
> 7f880000 419e04b0 38000000 6000e002 7f880000 419e06b0 801c0004 70090003 
> 418201c4 70090003 7c000026 54001ffe <0f000000> 61092000 b13f0002 a11f0002 
>  VFS: Mounted root (jffs2 filesystem).
> Freeing unused kernel memory: 128k init
> jffs2_lookup()
> jffs2_read_inode(): inode->i_ino == 3
> [JFFS2 DBG] (1) jffs2_do_read_inode: read inode #3
> [JFFS2 DBG] (1) jffs2_do_read_inode_internal: ino #3 nlink is 1
> [JFFS2 DBG] (1) jffs2_get_inode_nodes: ino #3
> 
> [SNIP] alot of output

I am starting to think that this error is due to an old design mistake
in JFFS2 I pointed out years ago: crc32 sums are seeded with zero instead of -1

Zero seed makes an zeroed JFFS2 header match its crc32 and that is what I think
is happening here, readinode.c:576 should reject this node but doesn't due to this flaw)

What to do:
1) Add extra checks for zeroed headers?
2) Add an config option where one can change the crc32 seed to -1?

 Jocke

Re: JFFS2 OOPS in 2.6.20

[David Woodhouse]

On Fri, 2007-03-09 at 10:36 +0100, Joakim Tjernlund wrote:
> I am starting to think that this error is due to an old design mistake
> in JFFS2 I pointed out years ago: crc32 sums are seeded with zero instead of -1

Indeed. But you only pointed it out in 2004, which was 3 years too
late :)
 
> Zero seed makes an zeroed JFFS2 header match its crc32 and that is what I think
> is happening here, readinode.c:576 should reject this node but doesn't due to this flaw)
> 
> What to do:
> 1) Add extra checks for zeroed headers?

That's the approach in the patch I just sent you.

> 2) Add an config option where one can change the crc32 seed to -1? 

If we're going to change it, why not change to something cheaper, like
Adler32? As you also pointed out. I suspect we should just leave it as
it is with the extra checks though.

-- 
dwmw2

Re: JFFS2 OOPS in 2.6.20

[Joakim Tjernlund]

On Fri, 2007-03-09 at 09:46 +0000, David Woodhouse wrote:
> On Fri, 2007-03-09 at 10:36 +0100, Joakim Tjernlund wrote:
> > I am starting to think that this error is due to an old design mistake
> > in JFFS2 I pointed out years ago: crc32 sums are seeded with zero instead of -1
> 
> Indeed. But you only pointed it out in 2004, which was 3 years too
> late :)

Someone got his archive in order :)

>  
> > Zero seed makes an zeroed JFFS2 header match its crc32 and that is what I think
> > is happening here, readinode.c:576 should reject this node but doesn't due to this flaw)
> > 
> > What to do:
> > 1) Add extra checks for zeroed headers?
> 
> That's the approach in the patch I just sent you.
> 
> > 2) Add an config option where one can change the crc32 seed to -1? 
> 
> If we're going to change it, why not change to something cheaper, like
> Adler32? As you also pointed out. I suspect we should just leave it as
> it is with the extra checks though.

Yeah, but I figured that changing seed was less intrusive. Not 
sure how good Alder32 is but if we make an incompatible change we
could change it to something else than crc32. We should measure if 
how much faster Adler32 is first though.

You think such a change is worthwhile?

 Jocke

Re: JFFS2 OOPS in 2.6.20

[Jörn Engel]

On Fri, 9 March 2007 11:56:20 +0100, Joakim Tjernlund wrote:
> 
> Yeah, but I figured that changing seed was less intrusive. Not 
> sure how good Alder32 is but if we make an incompatible change we
> could change it to something else than crc32. We should measure if 
> how much faster Adler32 is first though.
> 
> You think such a change is worthwhile?

Last time we discussed this, crc32 looked better.  It may be a bit
slower (not much, iirc), but it will catch _all_ 1-bit, 2-bit and 3-bit
errors and has a 1:2^32 change of missing n-bit errors with n>3.

Adler, if memory serves, can only guarantee all 1-bit errors and a
1:2^30 or so chance for n-bit errors, if the buffer is long enough.
"Long enough" is ~1000 bytes.  Below that, chances of getting false
positives are getting higher.

You can check the archives for this.  It might have been 2004 as well.

Jörn

-- 
There are two ways of constructing a software design: one way is to make
it so simple that there are obviously no deficiencies, and the other is
to make it so complicated that there are no obvious deficiencies.
-- C. A. R. Hoare