New thread [BUG] JFFS2 usage of write_begin and write_end functions causes kernel panic

New thread [BUG] JFFS2 usage of write_begin and write_end functions causes kernel panic

[James]

Hi,

I've just subscribed.  I saw this in the archives and it matches exactly
what I'm seeing on an AT91SAM9263-EK board.  I have 4 such boards.  2
work ok, the other 2 exhibit this problem.  I'm using 2.6.24 + patches
from linux4sam.org.  I'm using soft ECC.  There are no bad blocks
detected by U-boot.

mtd->read(0x44 bytes from 0x33f1fdc) returned ECC error
Node CRC 6331fb4e != calculated CRC db9ac943 for node at 033f1fdc
kernel BUG at fs/jffs2/file.c:251!
Unable to handle kernel NULL pointer dereference at virtual address
00000000
pgd = c3de0000
[00000000] *pgd=23dea031, *pte=00000000, *ppte=00000000
Internal error: Oops: 817 [#1]

<snip>

Backtrace: 
[<c002afa8>] (__bug+0x0/0x2c) from [<c0105ac0>] (jffs2_write_end
+0x48/0x2ec)
[<c0105a78>] (jffs2_write_end+0x0/0x2ec) from [<c0063120>]
(generic_file_buffered_write+0x190/0x62c)
[<c0062f90>] (generic_file_buffered_write+0x0/0x62c) from [<c00639dc>]
(__generic_file_aio_write_nolock+0x420/0x470)
[<c00635bc>] (__generic_file_aio_write_nolock+0x0/0x470) from
[<c0063aa4>] (generic_file_aio_write+0x78/0xf4)
[<c0063a2c>] (generic_file_aio_write+0x0/0xf4) from [<c007f3f4>]
(do_sync_write+0xbc/0x10c)
[<c007f338>] (do_sync_write+0x0/0x10c) from [<c007fce0>] (vfs_write
+0xb8/0x148)
[<c007fc28>] (vfs_write+0x0/0x148) from [<c00802ac>] (sys_write
+0x44/0x70)
 r7:00000004 r6:c3f9b8a0 r5:00000000 r4:00002000
[<c0080268>] (sys_write+0x0/0x70) from [<c0026de0>] (ret_fast_syscall
+0x0/0x2c)
 r6:4001b000 r5:00001000 r4:002a3790
Code: e1a01000 e59f000c eb004874 e3a03000 (e5833000) 
---[ end trace 4f4710199a7699a4 ]---
Segmentation fault
mtd->read(0x19f bytes from 0x33d1f54) returned ECC error

Did the change suggested here
http://lists.infradead.org/pipermail/linux-mtd/2008-April/021473.html
help?

<quote>
diff --git a/fs/jffs2/file.c b/fs/jffs2/file.c
index 5e92034..a146bf4 100644
--- a/fs/jffs2/file.c
+++ b/fs/jffs2/file.c
@@ -99,7 +99,7 @@ static int jffs2_do_readpage_nolock (struct inode *inode, struct page *pg)
  	kunmap(pg);

  	D2(printk(KERN_DEBUG "readpage finished\n"));
-	return 0;
+	return ret;
  }

  int jffs2_do_readpage_unlock(struct inode *inode, struct page *pg)
</quote>

I realise I should not have started a new thread, so is there a way I
could reply to a message on the list archive?

Regards,
James.

Re: New thread [BUG] JFFS2 usage of write_begin and write_end functions causes kernel panic

[David Woodhouse]

On Fri, 2008-05-09 at 15:51 +1000, James wrote:
> I've just subscribed.  I saw this in the archives and it matches
> exactly what I'm seeing on an AT91SAM9263-EK board.  I have 4 such
> boards.  2 work ok, the other 2 exhibit this problem.  I'm using
> 2.6.24 + patches from linux4sam.org.  I'm using soft ECC.  There are
> no bad blocks detected by U-boot.

You possibly need the patch in commit abe2f4143?

> I realise I should not have started a new thread, so is there a way I
> could reply to a message on the list archive?

The first link on the archived mail, despite appearing to be the address
of the person who sent the mail, actually has a mailto: link which will
send mail to the list -- and will get the threading right, if your MUA
is behaving itself properly.

-- 
dwmw2

Re: New thread [BUG] JFFS2 usage of write_begin and write_end functions causes kernel panic

[James]

On Fri, 2008-05-09 at 09:12 +0100, David Woodhouse wrote:
> You possibly need the patch in commit abe2f4143?

I'd love to, but (embarrassed) how do I find it?  I was searching in
http://git.infradead.org/mtd-2.6.git , but didn't see how to search for
a commit number.  Also the link the the GIT HOWTO timed out on several
attempts to view it.

> The first link on the archived mail, despite appearing to be the address
> of the person who sent the mail, actually has a mailto: link which will
> send mail to the list -- and will get the threading right, if your MUA
> is behaving itself properly.

I see, thanks.

Regards,
James.

Re: New thread [BUG] JFFS2 usage of write_begin and write_end functions causes kernel panic

[David Woodhouse]

On Mon, 2008-05-12 at 08:31 +1000, James wrote:
> I'd love to, but (embarrassed) how do I find it?  I was searching in
> http://git.infradead.org/mtd-2.6.git , but didn't see how to search
> for a commit number.

Just type it.
http://git.infradead.org/mtd-2.6.git?a=commitdiff;h=abe2f4143

>  Also the link the the GIT HOWTO timed out on several
> attempts to view it.

Yeah, due to a generator failure that machine is down until Monday
morning (UK time).

-- 
dwmw2

Re: New thread [BUG] JFFS2 usage of write_begin and write_end functions causes kernel panic

[James]

On Sun, 2008-05-11 at 23:41 +0100, David Woodhouse wrote:
> On Mon, 2008-05-12 at 08:31 +1000, James wrote:
> > I'd love to, but (embarrassed) how do I find it?  I was searching in
> > http://git.infradead.org/mtd-2.6.git , but didn't see how to search
> > for a commit number.
> 
> Just type it.
> http://git.infradead.org/mtd-2.6.git?a=commitdiff;h=abe2f4143


Ooo!  I like it.  Thanks again.  Will see if it works.

Cheers,
James.

Re: New thread [BUG] JFFS2 usage of write_begin and write_end functions causes kernel panic

[James]

On Sun, 2008-05-11 at 23:41 +0100, David Woodhouse wrote:
> Just type it.
> http://git.infradead.org/mtd-2.6.git?a=commitdiff;h=abe2f4143

It seems better.  I still get bucket loads of;

mtd->read(0x62c bytes from 0x3204608) returned ECC error

and the occasional;

Data CRC failed on REF_PRISTINE data node at 0x0331540c: Read
0x503a4071, calculated 0x52c053a8

but no more kernel oops, which makes me much happier.

Any ideas on the above two mentioned warnings?  Are they the result of
unclean NAND oob data, or kernel bugs, or something else?

Regards,
James.

Re: New thread [BUG] JFFS2 usage of write_begin and write_end functions causes kernel panic

[James]

On Mon, 2008-05-12 at 10:01 +1000, James wrote:
> On Sun, 2008-05-11 at 23:41 +0100, David Woodhouse wrote:
> > Just type it.
> > http://git.infradead.org/mtd-2.6.git?a=commitdiff;h=abe2f4143
> 
> It seems better.  I still get bucket loads of;
> 
> mtd->read(0x62c bytes from 0x3204608) returned ECC error
> 
> and the occasional;
> 
> Data CRC failed on REF_PRISTINE data node at 0x0331540c: Read
> 0x503a4071, calculated 0x52c053a8
> 
> but no more kernel oops, which makes me much happier.
      ^^^^^^^
Scrub that.  I just got an oops.  Same place as before
(fs/jffs2/file.c:251), but far less frequent than before.

> Any ideas on the above two mentioned warnings?  Are they the result of
> unclean NAND oob data, or kernel bugs, or something else?

I guess there are still some bugs to squash.

Regards,
James.

Re: New thread [BUG] JFFS2 usage of write_begin and write_end functions causes kernel panic

[James]

On Mon, 2008-05-12 at 13:24 +1000, James wrote:
> I guess there are still some bugs to squash.

Even with 2.6.20, there are still buckets of ECC and Checksum type
errors, even after a complete erase and reload of the original JFFS2
file system.

What can I do to find out what's going wrong?  Are there postmortem
tools for JFFS2 , that I can use to analyse an image retrieved from the
device?  The SAM-BA utility allows me to read the NAND flash.

I thought JFFS2 on NAND was fairly stable, so I'm a bit surprised by
these problems.  Could they be hardware related?  (This is on the
AT91SAM9263-EK board).

Below is with 2.6.20 from timesys, with JFFS2 and MTD debug turned up,
just trying to get a can4linux kernel module down to the dev board.

root@at91sam9263ek:~$ tftp -gr can.ko 192.168.70.104
jffs2_flush_wbuf(): Write failed with -5
About to refile bad block at 003e0000
Refiling block at 003e0000 to bad_used_list
Recovery of wbuf failed due to a second write error
Write of 420 bytes at 0x003eaf30 failed. returned -5, retlen 0
Not marking the space at 0x003eaf30 as dirty because the flash driver
returned retlen zero
mtd->read(0x1a4 bytes from 0xae0000) returned ECC error
JFFS2 error: (1243) __jffs2_dbg_prewrite_paranoia_check: argh, about to
write node to 0xae0000 on flash, but there are data already there. The
first corrupted byte is at 0xae01a4 offset.
kernel BUG at fs/jffs2/debug.c:151!
Unable to handle kernel NULL pointer dereference at virtual address
00000000
pgd = c3b8c000
[00000000] *pgd=239af031, *pte=00000000, *ppte=00000000
Internal error: Oops: 817 [#1]
Modules linked in:
CPU: 0
PC is at __bug+0x20/0x2c
LR is at 0x1
pc : [<c002713c>]    lr : [<00000001>]    Not tainted
sp : c3f65b80  ip : 00000000  fp : c3f65b8c
r10: c3d9fc00  r9 : c3f13528  r8 : 000001a4
r7 : 00ae0000  r6 : c3d9fc00  r5 : c3b88600  r4 : 000001a4
r3 : 00000000  r2 : c02db2d4  r1 : 01012ea2  r0 : 00000027
Flags: nZCv  IRQs on  FIQs on  Mode SVC_32  Segment user
Control: 5317F
Table: 23B8C000  DAC: 00000015
Process tftp (pid: 1243, stack limit = 0xc3f64258)
Stack: (0xc3f65b80 to 0xc3f66000)
5b80: c3f65bc4 c3f65b90 c0106874 c002712c 00ae01a4 c3f65ba4 c3b88600
c0038a1c 
5ba0: c029dcbc 000001a4 4f4ad012 c3b88400 00ae0000 c3b96220 c3f65c4c
c3f65bc8 
5bc0: c00fd018 c0106784 c01093a4 c0038a1c c3f65c0c c3f65be0 c01093c0
c023cf30 
5be0: 0000015a 000001a4 c02e32e4 00000200 c3b88400 c3f65c88 c3f65c8c
c39b4f68 
5c00: 00000000 00000002 c3f13528 00000044 c3b88400 00000160 c3f64000
c3f65c94 
5c20: c0038a30 00000000 00000000 00000200 c3d9fc00 00003000 c3f13528
c3b96220 
5c40: c3f65cc4 c3f65c50 c00fdbf0 c00fcf00 00000160 00000003 00001000
00000001 
5c60: 00000200 00000200 00000060 00000000 00000000 00000030 00000006
c3467000 
5c80: 00000000 00000001 00000160 00000200 0001ffc4 c3b88400 c00f8ffc
c3f13550 
5ca0: c3f13528 00000000 c3d9fc00 c3b96250 00000000 c037bce0 c3f65d14
c3f65cc8 
5cc0: c00f65dc c00fd8d0 00003000 00000200 c3f65ce4 00000003 00000200
00000200 
5ce0: 000c4414 00000000 c3f65d14 c3f64000 00000200 00000000 00000200
c037bce0 
5d00: 000c4414 00000000 c3f65dbc c3f65d18 c005adcc c00f6428 00000001
c3f65e90 
5d20: 00000001 00000200 c3b216e0 c3b962e8 c0243654 c3b96250 c3f65f20
00000000 
5d40: c3f64000 00000000 c3f65d9c 00000001 00000000 c037bce0 c3f65d8c
c3f65d68 
5d60: c003c89c c003c2b4 000000ee 14ef3429 9c80000c c3f65d90 c3b96250
00000000 
5d80: c3f65dbc c3f65d90 c0088f90 fe03c850 000000ee 00000200 00000001
00003000 
5da0: 00000000 c3b96250 00000000 00000200 c3f65e44 c3f65dc0 c005b478
c005a998 
5dc0: 00003000 00000000 c3f65ee0 00000200 00000000 c021a250 c005d85c
c3f65ee0 
5de0: c3f65f20 c3f65e90 ffffffff 00000000 c3b216e0 c3b962e8 00000000
00000001 
5e00: c3c2f580 00000000 00000000 00000000 00000020 c3c2f580 c004c13c
c3b962bc 
5e20: c3b96250 c3f65e90 c3f65f20 000035e84 c3f65e48 
5e40: c005b540 c005afe8 00000000 c00825d8 c3b216e0 c3b962e8 00000000
c3f65e90 
5e60: c3b216e0 c3f65e90 c3f65f20 c3f65f78 c3f64000 fffffdee c3f65f4c
c3f65e88 
5e80: c0074f74 c005b4d8 00003000 00000000 bec34c9c c3f65ed4 00000000
00000001 
5ea0: ffffffff c3b216e0 00000000 00000000 00000000 00000000 c3c2f580
c3f65ed4 
5ec0: 00000000 00000000 c01d4588 c3c2f580 c004c13c c3f65ed4 c3f65ed4
00000000 
5ee0: 00003000 00000000 c3f64000 00000000 c3f65fa4 00000000 c3bffc20
00000200 
5f00: c3b8d000 00000000 00000000 00000002 c03ac800 00000000 00000000
c3b9634c 
5f20: 000c4414 00000200 c3b216e0 000c4414 c3f65f78 00000200 c0022ec8
00000000 
5f40: c3f65f74 c3f65f50 c0075900 c0074ec8 00000005 c3f65ed4 00003000
00000000 
5f60: c3b216e0 00000004 c3f65fa4 c3f65f78 c0075fa4 c0075858 00003000
00000000 
5f80: bec34c74 00000000 bec34c9c 00000019 00000200 000c4414 00000000
c3f65fa8 
5fa0: c0022d20 c0075f70 00000019 00000200 00000003 000c4414 00000200
00000019 
5fc0: 00000019 00000200 000c4414 00000004 00000003 000c4412 00000000
00000019 
5fe0: 00000000 bec34ba8 0004e73c 401715ac 60000010 00000003 401ab914
401d5ffc 
Backtrace: 
[<c002711c>] (__bug+0x0/0x2c) from [<c0106874>]
(__jffs2_dbg_prewrite_paranoia_check+0x100/0x120)
[<c0106774>] (__jffs2_dbg_prewrite_paranoia_check+0x0/0x120) from
[<c00fd018>] (jffs2_write_dnode+0x128/0x5f8)
 r7 = C3B96220  r6 = 00AE0000  r5 = C3B88400  r4 = 4F4AD012
[<c00fcef0>] (jffs2_write_dnode+0x0/0x5f8) from [<c00fdbf0>]
(jffs2_write_inode_range+0x330/0x4e0)
[<c00fd8c0>] (jffs2_write_inode_range+0x0/0x4e0) from [<c00f65dc>]
(jffs2_commit_write+0x1c4/0x348)
[<c00f6418>] (jffs2_commit_write+0x0/0x348) from [<c005adcc>]
(generic_file_buffered_write+0x444/0x650)
[<c005a988>] (generic_file_buffered_write+0x0/0x650) from [<c005b478>]
(__generic_file_aio_write_nlock+0x4a0/0x4f0)
[<c005afd8>] (__generic_file_aio_write_nolock+0x0/0x4f0) from
[<c005b540>] (generic_file_aio_write+0x78/0xf4)
[<c005b4c8>] (generic_file_aio_write+0x0/0xf4) from [<c0074f74>]
(do_sync_write+0xbc/0x10c)
[<c0074eb8>] (do_sync_write+0x0/0x10c) from [<c0075900>] (vfs_write
+0xb8/0x190)
[<c0075848>] (vfs_write+0x0/0x190) from [<c0075fa4>] (sys_write
+0x44/0x70)
 r7 = 00000004  r6 = C3B216E0  r5 = 00000000  r4 = 00003000
[<c0075f60>] (sys_write+0x0/0x70) from [<c0022d20>] (ret_fast_syscall
+0x0/0x2c)
 r6 = 000C4414  r5 = 00000200  r4 = 00000019 
Code: e1a01000 e59f000c eb004633 e3a03000 (e5833000) 
 Segmentation faul<7>jffs2_follow_link(): target path is 'volatile/log'
t
root@at91sam926jffs2_follow_link(): target path is 'volatile/log'
3ek:~$ jffs2_follow_link(): target path is 'volatile/log'
jffs2_follow_link(): target path is 'volatile/log'
jffs2_follow_link(): target path is 'volatile/log'
jffs2_follow_link(): target path is 'volatile/log'
jffs2_follow_link(): target path is 'volatile/log'


Below is from 2.6.24 with patches from linnux4sam.org and JFFS2 and MTD
debug turned up.  Although this isn't a crash, it doesn't look good to
me.

root@at91sam9263ek:~$ tftp -gr can.ko 192.168.70.104
jffs2_flush_wbuf(): Write failed with -5
About to refile bad block at 003e0000
Refiling block at 003e0000 to bad_used_list
Write of 1499 bytes at 0x003ecec4 failed. returned -5, retlen 0
Not marking the space at 0x003ecec4 as dirty because the flash driver
returned retlen zero
jffs2_flush_wbuf(): Write failed with -5
About to refile bad block at 03e60000
Refiling block at 03e60000 to bad_used_list
Write of 1499 bytes at 0x03e607cc failed. returned -5, retlen 0
Not marking the space at 0x03e607cc as dirty because the flash driver
returned retlen zero
tftp: Write Error: Input/ouc3d6864c is on list at c3dd28d8
tput error
c3d6864c is on list at c3dd28d8
c3d6864c is on list at c3dd28d8
c3d6864c is on list at c3dd28d8
c3d6864c is on list at c3dd28d8
c3d6864c is on list at c3dd28d8
c3d6864c is on list at c3dd28d8
root@at91sam9263ek:~$ nand_isbad_bbt(): bbt info for offs 0x03f60000:
(block 507) 0x00
jffs2_flush_wbuf(): Write failed with -5
About to refile bad block at 03e40000
Refiling block at 03e40000 to bad_used_list
Write of 120 bytes at 0x03e407fc failed. returned -5, retlen 0
Not marking the space at 0x03e407fc as dirty because the flash driver
returned retlen zero

I am not a kernel hacking guru, or file system debugging wizard, but if
someone is willing to take a look, I'm happy to test things and report
back.

Regards,
James.

Re: New thread [BUG] JFFS2 usage of write_begin and write_end functions causes kernel panic

[James]

On Thu, 2008-05-15 at 17:01 +0800, Jason Liu wrote:
> Maybe, you need pay attention to the BBM

Not knowing offhand what "BBM" is, I'm guess it is bad block management?
I only see reference to this in the onenand driver.

I've now cross compiled the mtd-utils, as I couldn't get the Debian ARM
package for the same to run on my AT91SAM9263-EK board.  I have 2
partitions, the first starting at 0x100000 and finishing 504 blocks
later, i.e. 128kB * 504 = 63MB, 1MB is reserved at the beginning for
U-boot and it's env.  There were no bad blocks detected on the device as
it was shipped from the factory.

Running an ext3 fs on a USB stick as the RFS with noatime and nodiratime
options, I can test the NAND interface.

So I tried this...

root@at91sam9263ek:~/mtd-tools$ ./flash_eraseall  /dev/mtd0 0 504
Erasing 128 Kibyte @ 3ee0000 -- 99 % complete.
root@at91sam9263ek:~/mtd-tools$ ./nandtest -p 5 -o 0 /dev/mtd0
ECC corrections: 0
ECC failures   : 3
Bad blocks     : 0
BBT blocks     : 0
00000000: reading... 
ECC failed at 00000000
00000000: checking...
compare failed. seed 1804289383
Byte 0x7c40 is 0c should be ff
Byte 0xa58f is 0c should be ff
Byte 0xd010 is 55 should be 83
Byte 0xd011 is 38 should be fb
Byte 0xd050 is 12 should be a8
Byte 0xd051 is 74 should be 90
Byte 0xd090 is c8 should be 89
Byte 0xd091 is 86 should be c9
Byte 0xd0d0 is 41 should be 48
Byte 0xd0d1 is b3 should be c3
Byte 0xd110 is c3 should be 09
Byte 0xd111 is d1 should be 73

Hmm.  This does not look good to me.  Does this indicate a hardware or
software problem?  Or did I misuse the tools?  What tests should/could I
perform?

Regards,
James.

Re: New thread [BUG] JFFS2 usage of write_begin and write_end functions causes kernel panic

[James]

On Mon, 2008-05-12 at 08:31 +1000, James wrote:
> On Fri, 2008-05-09 at 09:12 +0100, David Woodhouse wrote:
> > You possibly need the patch in commit abe2f4143?
> 
> I'd love to, but (embarrassed) how do I find it?  I was searching in
> http://git.infradead.org/mtd-2.6.git , but didn't see how to search for
> a commit number.  Also the link the the GIT HOWTO timed out on several
> attempts to view it.

I think I found what you are talking about in here:
http://www2.kernel.org/pub/linux/kernel/v2.6/ChangeLog-2.6.25

commit abe2f41430770270a1512bf78f489284bfbdbd04
Author: Alexey Korolev <akorolev@infradead.org>
Date:   Mon Apr 14 20:45:06 2008 +0100

    JFFS2 Fix of panics caused by wrong condition for hole frag creation in write_begin

Is that what you meant?

Regards,
James.

Re: New thread [BUG] JFFS2 usage of write_begin and write_end functions causes kernel panic

[Anders Grafström]

James wrote:
> Did the change suggested here
> http://lists.infradead.org/pipermail/linux-mtd/2008-April/021473.html
> help?

It avoids a panic if you have set panic-on-oops but the write operation fails
for the application. write(2) returning a short write count is what I saw.

Anders