JFFS2 Corruption.

I am having problems using JFFS2 filesystems on a NAND device. I have had these problems in the past an decided not to use this method for storing my data. I would really like to do this and I was wondering if anyone else had been able to run such a system reliably ? The NAND device is a 128MB SMC and I have downloaded the mtd code from CVS within the last week.

I am using mtdpart to provide partitions but for the moment I am only using mtd1 as a root file system. To build this I perform the following steps.

1. Boot system via network and mount nfs root
2. eraseall /dev/mtd1
3. mount -t jffs2 /dev/mtdblock1 /smc
4. cd /smc
5. tar xvzf /rootfilesystem.tgz
6. unmount /smc

I then reboot using the SMC as my root filesystem. As the system gets rebooted and incurrs more writes I get the following kinds of message

Empty flash at 0x00469ffcb ends at 0x0046a000

or

jffs2_scan_dirent_node(): Node CRC failed on node at 0x0046a7f0 read 0xffffffff calculated 0xdec8161b

I have written in before about these messages and I understand that the first is of no concern but the second relates to write data which may not have been written to the SMC.

The thing is I have had this happen on two completely different harware designs. On an X86 board and the other a PPC.

I have checked and the OS umounts root as it shuts down. Also I cannot find fsck.jffs2 in the util directory. Does it exist ?

In trying to debug this I noticed that the device was still reporting busy when nand_command was entered. I have put a line of code in to delay until the device is ready at the start of the routine. It is my understanding that if the device is busy when you try and select/deselect or send a command the outcome cannot be predicted. If this is not the case I would like to understand why. If it is how does any of the NAND code work ?

Any help greatly appreciated

Cheers Simon.

__________________________

Simon Haynes - Baydel
Phone : 44 (0) 1372 378811
Email : [email protected]
__________________________

As I have been trying to use this as a root filesystem I checked made checks into the dismounting of the filesystem. It seems that the halt script remounts root read only. However I found that this does not cause mtdblock to flush it's cache. I have written a small program to perform an ioctl BLKFLSBUF and I call it after the system mounts root read only. This seems to help but it is not the whole story.

I have also trawled the archives. There are some articles which list similar problems. It is proposed that these are related to unaligned memory access. Can anyone explain why this matters and how to prevent it.

My current architecture is PPC.

Many Thanks

Simon.

__________________________

Simon Haynes - Baydel
Phone : 44 (0) 1372 378811
Email : [email protected]
__________________________

Comitted the sin of posting a reply with the reply text first, sorry.

I have only managed to get this to fail if the jffs2 filesystem is mounted as root. I do not seem to be able to get it to close and unmount the filesystem at shutdown. I guess the BLKFLSBUF I do only flushes the buffer that is created when I open the device and not the one that was created when the kernel opened the device.

My current thoughts are to create a ro root and and additional rw. Is there a better way that I can do this ?

Cheers

Simon. __________________________

Simon Haynes - Baydel
Phone : 44 (0) 1372 378811
Email : [email protected]
__________________________

And this time you committed the sin of including _far_ more of the previous mail(s) than was necessary. But I'm not feeling cruel today so I'll not continue to ignore you :)

JFFS2 doesn't actually _use_ the mtdblock device. If you look closely at the code, you'll see we never read or write to/from it, we just use the minor number as an argument to get_mtd_device().

In fact, it's perfectly possible to use any _other_ device driver instead of the mtdblock device, as long as it has the major number which JFFS2 is looking for.

I wonder if the rootfs-mounting is opening the _actual_ block device and doing some I/O, and that's later getting flushed, causing corruption. Although I can't comprehend why a failed attempt to mount, for example, ext2 would cause the mtdblock device to consider its buffer _dirty_ and try to write it back on close.

What happens if you use the 'mtdblock_ro' device instead? That shares the major number, but doesn't share the caching.

dwmw2

Thanks for the reply I am really struggling with this. I appreciate that this stuff keeps you really busy and I will try to make it as easy for you as I can.

I only seem to get this problem if I use the SMC as root. I have put a prink in mtdblock.c which tells me when the flush and release modules are called. After trawling thw archives I also set the debugging level to 1. Now I get the message mtdblock_open \n ok when the kernel mounts root.

If I boot from the network, mount the SMC, build a JFFS2 filesystem,copy files, on umount I get a release message. I can then reboot via the network and make changes to the JFFS2 filesystem., many times, and all is ok. If I boot my system and I pass the root=/dev/mtdblock1 argument to the kernel it comes up fine on the SMC. This modifies mainly files in /var. If I then reboot the system I do not get any messages from the mtdblock flush or release routines. Next time the filesystem is mounted it is corrupt.

I have looked int the util/MAKEDEV file and the readme but I don't know how to select the mtdblock_ro device.

I take it what I am trying to do is possible and is suitable for a production environment ?

Thanks again

Simon

Ah, I see the ro stuff is a kernel change. I will give it a go.

Cheers Simon.

I don't understand. I changed the kernel to use the read only device. I expected this to work rw without caching but it does not. I have already tried mounting root ro via the caching mtd block and although my system does not fully start I can't see how I would get corruption ?

I have looked at the mtdblock_ro code and it seems you allow writing if flag certain bits are set you allow writing. Do I need to set these somewhere ?

Cheers Simon.

You can't use flash RW without caching. It _has_ to read/modify/erase/writeback to write to flash.

But for JFFS2, you _don't_ use flash RW through mtdblock. It operates directly and should work fine. What failure mode do you observe?

As I said -- I don't know. Maybe there's a bug which causes the mtdblock device to consider its cache dirty, and write it out to the detriment of the real data which JFFS2 has already put there on the flash. That's why I was asking you to test mtdblock_ro.

No. Leave them turned off. We don't actually want to write via the mtdblock device -- that's the whole _point_ in this experiment.

dwmw2

The problem is when I mount the erased partition using

mount -t jffs2 /dev/mtdblock1 /smc

/smc is mounted read only and I cannot write to it.

surely this is the same as not remounting root read write ?

Cheers Simon.

Hmmm. What happens if you mount -oremount,rw?

dwmw2

I have just created the fs with a rw mtdblock kernel and rebooted with a ro mtdblock. This attempts to remount rw but it cannot.

I have tried booting from the network with a ro mtdblock kernel and performing the following operation.

-bash-2.05b# mount -t jffs2 /dev/mtdblock2 /smc
mount: block device /dev/mtdblock2 is write-protected, mounting read-only -bash-2.05b# mount -oremount,rw /smc
mount: block device /dev/mtdblock2 is write-protected, mounting read-only -bash-2.05b# cat /proc/mounts
rootfs / rootfs rw 0 0
/dev/root / nfs rw,v2,rsize=4096,wsize=4096,hard,udp,nolock,addr=192.9.200.22 0 0
/proc /proc proc rw 0 0
/dev/mtdblock2 /smc jffs2 ro 0 0
-bash-2.05b#

I guess this is not how things are supposed to work. Are there any kernel settings I should check ?

Cheers

Simon.

Hmm. OK, hack jffs2 to use the same major number as ramdisk, then try to mount /dev/ram2 instead :)

dwmw2

I hacked fs/jffs2/super.c and fs/jffs2/super_v24.c. Only the v24 got compiled. I guess this is because my kernel is 2.4.21. I had to also include ramdisk in the kernel as it was previously missing ? Does this effect MTD ? This mounted rw.

-bash-2.05b# ls -l /dev/ram2
brw-rw---- 1 root disk 1, 2 Jan 31 2003 /dev/ram2
-bash-2.05b# mount -t jffs2 /dev/ram2 /smc
-bash-2.05b# cat /proc/mounts
rootfs / rootfs rw 0 0
/dev/root / nfs rw,v2,rsize=4096,wsize=4096,hard,udp,nolock,addr=192.9.200.22 0 0
/proc /proc proc rw 0 0
/dev/ram2 /smc jffs2 rw 0 0
-bash-2.05b#

No, it neither effects nor affects the MTD drivers.

OK... now can you reproduce the same _problem_ that way?

dwmw2

My problem only occurs across reboots. As the ramdisk is not persistent storage how can I try and reproduce the problem. I have tried to reproduce the problem on mtd devices without rebooting and I have not managed to to this.

Cheers

SImon.

The ramdisk isn't _involved_ as a form of storage. JFFS2 doesn't _use_ the block device for _anything_ except for looking at its minor number to decide which actual MTD device to use.

Hack JFFS2 to always get_mtd_device number 2 and boot with root=/dev/ram0

dwmw2

Sorry again for being so stupid. I know you have only told me half a dozen times that JFFS2 does not use the block read and write routines.

I have done this and rebooted several times. Normally I would expect a CRC error within a couple or reboots. As yet I have no CRC errors but I do get a large number of "Empty Flash" messages, about 15 per reboot. I do not see any of these if I boot via the network and mount and dismount the smc ?

I will keep rebooting over night and hack the kernel to panic on a CRC error.

Would you recommend changing the printk for the "Empty Flash" messages to a different level and using the ramdisk as a permanent solution ?

Changing the printk level for the 'Empty Flash' messages does seem appropriate -- or preferably finding a way to eliminate the ones which we don't want. Are you mounting the fs read-only before rebooting? If not, the occasional CRC failure is acceptable. You get those with an unclean restart. It doesn't indicate data loss; it indicates that one particular log entry which you were writing _while_ you rebooted was lost. That was not data which userspace thought was already on the medium.

The problem with mtdblock is interesting. Can you make it BUG() when it dirties its cache and put it back to how it was, using mtdblock?

dwmw2

I do remount the filesystem read only as part of a shutdown. I also cat /proc/mounts so that I can check it has happened. So the filesystem should be clean. After this halt is called. I think this tries to write to utmp. If the kernel already has the device open for write will this be allowed ?

I guess it is strange that the read only mtdblock device prevents write access via jffs2. I don't know if the cache in mtdblock is ever being used but I can certainly put a BUG() in there.

Cheers

Simon.

Yesteday I managed to reproduce the problem using /dev/ram. The first message I noticed was

jffs2_get_inode_nodes(): Data CRC failed on node at 0x00050748: Read 0x0b5da171, calculated 0xb1b1dbb

This happened some time after the kernel mounted root. On following reboots this message was not displayed but I did get one

jffs2_scan_dirent_node(): Node CRC failed on node at 0x0046a7f0 read 0xffffffff calculated 0xdec8161b

message.

As I do mount read only on shutdown I assume this is corruption ?

Cheers

Simon.

__________________________

Simon Haynes - Baydel
Phone : 44 (0) 1372 378811
Email : [email protected]
__________________________

Maybe. I doubt it's _harmful_ but I am very interested.

Any chance you can run with CONFIG_JFFS2_FS_DEBUG=1 and log _all_ the messages over a serial console, then see what it wrote at the offending address when you get a CRC error?

dwmw2

This has taken some time to produce. I have a 40Mb logfile which thankfully compresses to 4Mb. To generate the log I booted the system via the network with JFFS2 patched to use /dev/ram MAJOR, but no JFFS2 debug. I erased the SMC and made a clean JFFS2 filesystem. I then copied all of my root files. I mounted and umounted this a few times and each time I created and deleted a few files. I did not get one error.

I then rebooted using a similar kernel with CONFIG_JFFS2_FS_DEBUG=1 and passed arguments "root=/dev/ram1 debug".

It took about 6 hours before I could log in. I then halted the system. On the first reboot, fortunately, I did get a CRC error but I cannot find where this was previously written. The node is 0x000303f0.

I also observe the Empty flash XXXX ends at XXX. Which do not appear before the filesystem is used as rootfs and restarted.

Beyond that I don't really know what I am looking for in the log. I can mail it to you personally but as I said it's 4Mb compressed.

Cheers

Simon.
__________________________

Simon Haynes - Baydel
Phone : 44 (0) 1372 378811
Email : [email protected]
__________________________

Lemme see it. Although if there's a node at 0x000303f0 and no existence of 000303f0 in the logfile, your logfile is missing bits.

Also take a dump of the offending file system.

dwmw2

(for the benefit of the peanut gallery...)

The CRC error was harmless. It was a node being garbage-collected, which we didn't bother to finish writing because it contained only a redundant copy of data which existed elsewhere on the flash already.

We could try to be slightly quieter about such things, but then we might actually miss something which _is_ a problem. Better to be concerned when there isn't a problem, than to be blissfully unaware when there _is_ one. Perhaps.

dwmw2

As you suggested I have changed the JFFS2 remount code to flush wbuf when the filesystem is mounted read only. As I said via IRC I have performed tens of reboots and I have not seen any CRC messages.

Now on occasions, when the kernel is mounting JFFS2 as root on NAND I get.

NAND device: Manufacturer ID: 0xec, Chip ID: 0x79 (Samsung NAND 128MiB 3,3V) Creating 3 MTD partitions on "NAND 128MiB 3,3V":
0x00000000-0x01000000 : "Boot / config partition"
mtd: Giving out device 0 to Boot / config partition 0x01000000-0x05000000 : "JFFS2 Root Filesystem partition"
mtd: Giving out device 1 to JFFS2 Root Filesystem partition 0x05000000-0x08000000 : "Write Cache Backup partition"
mtd: Giving out device 2 to Write Cache Backup partition
NET4: Linux TCP/IP 1.0 for NET4.0
IP Protocols: ICMP, UDP, TCP
IP: routing cache hash table of 512 buckets, 4Kbytes
TCP: Hash tables configured (established 4096 bind 4096)
NET4: Unix domain sockets 1.0/SMP for Linux NET4.0.
jffs2: Erase block size too small (16KiB). Using virtual blocks size (32KiB) instead
ofs 0x00c00400 has already been seen. Skipping jffs2_scan_eraseblock(): Magic bitmask 0x1985 not found at 0x00c00408: 0x273c instead
jffs2_scan_eraseblock(): Magic bitmask 0x1985 not found at 0x00c00420: 0x404d instead
jffs2_scan_eraseblock(): Magic bitmask 0x1985 not found at 0x00c00424: 0x404d instead
jffs2_scan_eraseblock(): Magic bitmask 0x1985 not found at 0x00c00428: 0x404d instead
jffs2_scan_eraseblock(): Magic bitmask 0x1985 not found at 0x00c0043c: 0x0f33 instead
jffs2_scan_eraseblock(): Magic bitmask 0x1985 not found at 0x00c00440: 0x88f8 instead
jffs2_scan_eraseblock(): Magic bitmask 0x1985 not found at 0x00c00444: 0x4d61 instead
jffs2_scan_eraseblock(): Magic bitmask 0x1985 not found at 0x00c00448: 0x2039 instead
jffs2_scan_eraseblock(): Magic bitmask 0x1985 not found at 0x00c0044c: 0x343a instead
jffs2_scan_eraseblock(): Magic bitmask 0x1985 not found at 0x00c00450: 0x3a32 instead
Further such events for this erase block will not be printed

Can you suggest what might be going on ?

Cheers

Simon.

Since lunch interrupted our converstation yesterday I have tried a few things. The SMC partition I was using was 64 Mb and contained a bad block. I modified the kernel to make this partition 48Mb. I booted root over nfs and tried to rebuild root on the SMC. I can no longer mount the original SMC so I tried a new one which worked OK.

-bash-2.05b# /mtd/eraseall /dev/mtd1 > /dev/null
nand_erase: attempt to erase a bad block at page 0x0001ee60

/mtd/eraseall: /dev/mtd1: MTD Erase failure: Input/output error -bash-2.05b# mount -t jffs2 /dev/ram1 /smc
Cowardly refusing to erase blocks on filesystem with no valid JFFS2 nodes empty_blocks 2047, bad_blocks 0, c->nr_blocks 2048
mount: wrong fs type, bad option, bad superblock on /dev/ram1,
or too many mounted file systems
-bash-2.05b# /mtd/eraseall /dev/mtd1 > /dev/null
-bash-2.05b# mount -t jffs2 /dev/ram1 /smc
-bash-2.05b#

After 5 reboots the new SMC gave this magic bitmask failure.

jffs2: Erase block size too small (16KiB). Using virtual blocks size (32KiB) instead
ofs 0x000a8400 has already been seen. Skipping, jeb 0xa8000, sector size 0x8000
saved ofs 0x000a8000, previous 0xa7fff, buf_len 0x7c00, scanned 0x0 jffs2_scan_eraseblock(): Magic bitmask 0x1985 not found at 0x000a8408: 0x273c instead, 0x0
jffs2_scan_eraseblock(): Magic bitmask 0x1985 not found at 0x000a841c: 0x000b instead, 0x0
jffs2_scan_eraseblock(): Magic bitmask 0x1985 not found at 0x000a8420: 0x404d .
.
.

It would appear that the first buffer location does not contain 0xFFFFFFFF and cleanmarkerfound is set but I don't know what this means to JFFS2.

I then switched the partition back to 64Mb, set the kernel to use the read only block device and hacked the MAJOR number for JFFS2 to be the same as /dev/ram. I have rebooted the system at least 20 times and as yet I have not seen any errors.

I am unsure as where to go next besides trying more reboots.

Any ideas ?

Cheers

Simon.

This I believe we put down to user error?

That was a bug in the scanning code. Should be fixed in v1.58 of scan.c in CVS. Please could you try that and let me know if it works?

dwmw2

Yes, this was a problem I introduced when trying to track down why I got the Magic bitmask messages.

I have not had chance a yet to download scan from CVS. However I did make the simple change you suggested and everything worked fine.

Thankyou, Thankyou, Thankyou

Simom.

__________________________

Simon Haynes - Baydel
Phone : 44 (0) 1372 378811
Email : [email protected]
__________________________

What I committed was slightly more complicated -- and also broken. Thomas fixed it though. :)

dwmw2

CRC

After several more reboots I got the message

jffs2_get_inode_nodes(): Data CRC failed on node at 0x00050748: Read 0x0b5da171, calculated 0xb1b1dbb

This actually came out after I had logged in ?

I will also look into changing my list to irc.freenode.net.

Many Thanks

Simon.

Btw if you join #mtd on irc.freenode.net you may experience lower latency in getting responses.

dwmw2