JFFS2 errors on ppc-4xx with CFI NOR flash

JFFS2 errors on ppc-4xx with CFI NOR flash

[Ryan Thompson]

Hi,

We've been seeing errors on our ~32MiB jffs2 filesystem on a custom
ppc-4xx board with a Numonyx 128MiB CFI NOR flash (128KiB erase
blocks).

The filesystem is mounted from /dev/mtd/modules, which is a symlink to
/dev/mtdblock16, defined in the FDT as follows:

            /* Modules (32128 KiB) */
            partition@2e80000 {
                reg = <0x2E80000 0x1F60000>;
                label = "modules";
            };

When a significant amount of data (i.e., a few files over a few megs
each) is written to the filesystem, we start seeing erase block
errors, checksum failures, and garbage collection errors. However,
these same filesystems have been in steady R&D use on this hardware
and same 2.6.28 kernel for ~6 months without issue. Until recently our
use case has only involved writing a small number of tiny files. We
only started seeing errors when we began to write larger files.

(Console output is at the end of this message.)

I have been able to reproduce this problem on multiple systems with
the following script (/mnt is defined in fstab(5) as jffs2 with
noatime,noauto,rw):

--------------------------

#!/bin/sh

umount /mnt && mount /mnt
cd /mnt
df /mnt
while dd if=/dev/urandom of=`mktemp` count=512 2>/dev/null; do
    sync
    df /mnt | tail -1
done
echo "Filesystem full?"
sync; sync
df /mnt
rm *.tmp
sync; sync; sync
df /mnt | tail -1

--------------------------

The errors tend to occur just after df shows approximately 52-55%
(perhaps garbage collection starts around this time?)

This occurs on at least 2.6.31. After the errors occur, the filesystem
is unusable until I reboot the system (the errors just keep repeating,
all reads and writes fail). However when the system is rebooted the
filesystem seems to (silently) recover and be completely intact.

We saw essentially the same errors on 2.6.28, but the kernel would
panic. With 2.6.31, there is no panic, but a reboot is still necessary
to restore operation.

We use other partitions of the flash in block mode through mtdblockXX.
As a test, I also formatted mtdblock16 (the jffs2 partition) as vfat.
(Yes, I know how horrible this is!) With vfat, the above script filled
the filesystem 10 times without issue (except for significantly
reducing the lifespan of my flash part, I'm sure!) I additionally used
a more complex version of the above script in some of my trials to
store and verify the md5 sums of the random files written after the
vfat filesystem was full; all files verified successfully.

Here's the console output from one such incident:

----------- Console output --------------
Newly-erased block contained word 0x19850003 at offset 0x01f20000
Jan  1 00:06:15 rjt kernel: Newly-erased block contained word
0x19850003 at offset 0x01f20000
/dev/mtd/modules         32128     16916     15212  53% /mnt
Node totlen on flash (0xffffffff) != totlen from node ref (0x00000044)
Jan  1 00:06:16 rjt Node totlen on flash (0xffffffff) != totlen from
node ref (0x00000044)
kernel: Node totlen on flash (0xffffffff) != totlen from node ref (0x00000044)
Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
Jan  1 Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
00:06:16 TerraceNode CRC ffffffff != calculated CRC f09e7845 for node
at 01e162f0
Q kernel: Node totlen on flash (0xffffffff) != totlen from node ref (0x00000044)
Jan  1 00:06:16 rjtNewly-erased block contained word 0x19850003 at
offset 0x01d20000
 kerneNewly-erased block contained word 0x19850003 at offset 0x01d00000
l: Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
Filesystem full?
Jan  1 00:06:16 rjt last message 'kernel: Node totlen on flash
(0xffffffff) != totlen from node ref
Jan  1 00:06:16 rjt kernel: Node CRC ffffffff != calculated CRC
f09e7845 for node at 01e162f0
Jan  1 00:06:16 rjt kernel: Newly-erased block contained word
0x19850003 at offset 0x01d20000
Jan  1 00:06:16 rjt kernel: Newly-erased block contained word
0x19850003 at offset 0x01d00000
Filesystem           1K-blocks      Used Available Use% Mounted on
/dev/mtd/modules         32128     17172     14956  53% /mnt
rm: cannot remove '*.tmp': No such file or directory
/dev/mtd/modules         32128     17172     14956  53% /mnt
# Newly-erased block contained word 0x19850003 at offset 0x01ce0000
Jan  1Newly-erased block contained word 0x19850003 at offset 0x01ca0000
 00:06Newly-erased block contained word 0x19850003 at offset 0x01cc0000
:20 Newly-erased block contained word 0x19850003 at offset 0x01c80000
rjt kernel: Newly-erased block contained word 0x19850003 at offset 0x01ce0000
Jan  1 00:06:20 rjt kernel: Newly-erased block contained word
0x19850003 at offset 0x01ca0000
Jan  1 00:06:20 rjt kernel: Newly-erased block contained word
0x19850003 at offset 0x01cc0000
Jan  1 00:06:20 rjt kernel: Newly-erased block contained word
0x19850003 at offset 0x01c80000
Newly-erased block contained word 0x19850003 at offset 0x01c60000
Jan  1Newly-erased block contained word 0x19850003 at offset 0x01c40000
 00:06Newly-erased block contained word 0x19850003 at offset 0x01c20000
:25 rjNewly-erased block contained word 0x19850003 at offset 0x01c00000
t Newly-erased block contained word 0x19850003 at offset 0x01be0000
kernel:Newly-erased block contained word 0x19850003 at offset 0x01bc0000
 Newly-erased block contained word 0x19850003 at offset 0x01c60000
Jan  1 00:06:25 rjt kernel: Newly-erased block contained word
0x19850003 at offset 0x01c40000
Jan  1 00:06:25 rjt kernel: Newly-erased block contained word
0x19850003 at offset 0x01c20000
Jan  1 00:06:25 rjt kernel: Newly-erased block contained word
0x19850003 at offset 0x01c00000
Jan  1 00:06:25 rjt kernel: Newly-erased block contained word
0x19850003 at offset 0x01be0000
Jan  1 00:06:25 rjt kernel: Newly-erased block contained word
0x19850003 at offset 0x01bc0000
Newly-erased block contained word 0x19850003 at offset 0x01ba0000
Jan  1 Newly-erased block contained word 0x19850003 at offset 0x01b80000
00:06:Argh. No free space left for GC. nr_erasing_blocks is 0.
nr_free_blocks is 0. (erasableempty: yes, erasingempty: yes,
erasependingempty: yes)
26 rjtjffs2_reserve_space_gc of 196 bytes for garbage_collect_dnode failed: -28
 Error garbage collecting node at 01b6db84!
kerneNo space for garbage collection. Aborting GC thread
l: Newly-erased block contained word 0x19850003 at offset 0x01ba0000
Jan  1 00:06:26 rjt kernel: Newly-erased block contained word
0x19850003 at offset 0x01b80000
Jan  1 00:06:26 rjt kernel: Argh. No free space left for GC.
nr_erasing_blocks is 0. nr_free_blocks is 0. (erasableempty: yes,
erasingempty: yes, erasependingempty: yes)
Jan  1 00:06:26 rjt kernel: jffs2_reserve_space_gc of 196 bytes for
garbage_collect_dnode failed: -28
Jan  1 00:06:26 rjt kernel: Error garbage collecting node at 01b6db84!
Jan  1 00:06:26 rjt kernel: No space for garbage collection. Aborting GC thread

I'd of course welcome any advice or further debugging suggestions.

Thanks,
- R

Re: JFFS2 errors on ppc-4xx with CFI NOR flash

[massimo cirillo]

Hi,
Sorry my earlier message was rejected because
of suspicious header.

Ryan,
Please specify the complete part number of the
flash device and I'll try to help you. As first
attempt try to disable erase suspend feature in
the flash driver.

2010/3/4 Ryan Thompson <i@ry.ca>
>
> Hi,
>
> We've been seeing errors on our ~32MiB jffs2 filesystem on a custom
> ppc-4xx board with a Numonyx 128MiB CFI NOR flash (128KiB erase
> blocks).
>
> The filesystem is mounted from /dev/mtd/modules, which is a symlink to
> /dev/mtdblock16, defined in the FDT as follows:
>
>            /* Modules (32128 KiB) */
>            partition@2e80000 {
>                reg = <0x2E80000 0x1F60000>;
>                label = "modules";
>            };
>
> When a significant amount of data (i.e., a few files over a few megs
> each) is written to the filesystem, we start seeing erase block
> errors, checksum failures, and garbage collection errors. However,
> these same filesystems have been in steady R&D use on this hardware
> and same 2.6.28 kernel for ~6 months without issue. Until recently our
> use case has only involved writing a small number of tiny files. We
> only started seeing errors when we began to write larger files.
>
> (Console output is at the end of this message.)
>
> I have been able to reproduce this problem on multiple systems with
> the following script (/mnt is defined in fstab(5) as jffs2 with
> noatime,noauto,rw):
>
> --------------------------
>
> #!/bin/sh
>
> umount /mnt && mount /mnt
> cd /mnt
> df /mnt
> while dd if=/dev/urandom of=`mktemp` count=512 2>/dev/null; do
>    sync
>    df /mnt | tail -1
> done
> echo "Filesystem full?"
> sync; sync
> df /mnt
> rm *.tmp
> sync; sync; sync
> df /mnt | tail -1
>
> --------------------------
>
> The errors tend to occur just after df shows approximately 52-55%
> (perhaps garbage collection starts around this time?)
>
> This occurs on at least 2.6.31. After the errors occur, the filesystem
> is unusable until I reboot the system (the errors just keep repeating,
> all reads and writes fail). However when the system is rebooted the
> filesystem seems to (silently) recover and be completely intact.
>
> We saw essentially the same errors on 2.6.28, but the kernel would
> panic. With 2.6.31, there is no panic, but a reboot is still necessary
> to restore operation.
>
> We use other partitions of the flash in block mode through mtdblockXX.
> As a test, I also formatted mtdblock16 (the jffs2 partition) as vfat.
> (Yes, I know how horrible this is!) With vfat, the above script filled
> the filesystem 10 times without issue (except for significantly
> reducing the lifespan of my flash part, I'm sure!) I additionally used
> a more complex version of the above script in some of my trials to
> store and verify the md5 sums of the random files written after the
> vfat filesystem was full; all files verified successfully.
>
> Here's the console output from one such incident:
>
> ----------- Console output --------------
> Newly-erased block contained word 0x19850003 at offset 0x01f20000
> Jan  1 00:06:15 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01f20000
> /dev/mtd/modules         32128     16916     15212  53% /mnt
> Node totlen on flash (0xffffffff) != totlen from node ref (0x00000044)
> Jan  1 00:06:16 rjt Node totlen on flash (0xffffffff) != totlen from
> node ref (0x00000044)
> kernel: Node totlen on flash (0xffffffff) != totlen from node ref (0x00000044)
> Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
> Jan  1 Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
> Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
> Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
> Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
> Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
> Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
> 00:06:16 TerraceNode CRC ffffffff != calculated CRC f09e7845 for node
> at 01e162f0
> Q kernel: Node totlen on flash (0xffffffff) != totlen from node ref (0x00000044)
> Jan  1 00:06:16 rjtNewly-erased block contained word 0x19850003 at
> offset 0x01d20000
>  kerneNewly-erased block contained word 0x19850003 at offset 0x01d00000
> l: Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
> Filesystem full?
> Jan  1 00:06:16 rjt last message 'kernel: Node totlen on flash
> (0xffffffff) != totlen from node ref
> Jan  1 00:06:16 rjt kernel: Node CRC ffffffff != calculated CRC
> f09e7845 for node at 01e162f0
> Jan  1 00:06:16 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01d20000
> Jan  1 00:06:16 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01d00000
> Filesystem           1K-blocks      Used Available Use% Mounted on
> /dev/mtd/modules         32128     17172     14956  53% /mnt
> rm: cannot remove '*.tmp': No such file or directory
> /dev/mtd/modules         32128     17172     14956  53% /mnt
> # Newly-erased block contained word 0x19850003 at offset 0x01ce0000
> Jan  1Newly-erased block contained word 0x19850003 at offset 0x01ca0000
>  00:06Newly-erased block contained word 0x19850003 at offset 0x01cc0000
> :20 Newly-erased block contained word 0x19850003 at offset 0x01c80000
> rjt kernel: Newly-erased block contained word 0x19850003 at offset 0x01ce0000
> Jan  1 00:06:20 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01ca0000
> Jan  1 00:06:20 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01cc0000
> Jan  1 00:06:20 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01c80000
> Newly-erased block contained word 0x19850003 at offset 0x01c60000
> Jan  1Newly-erased block contained word 0x19850003 at offset 0x01c40000
>  00:06Newly-erased block contained word 0x19850003 at offset 0x01c20000
> :25 rjNewly-erased block contained word 0x19850003 at offset 0x01c00000
> t Newly-erased block contained word 0x19850003 at offset 0x01be0000
> kernel:Newly-erased block contained word 0x19850003 at offset 0x01bc0000
>  Newly-erased block contained word 0x19850003 at offset 0x01c60000
> Jan  1 00:06:25 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01c40000
> Jan  1 00:06:25 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01c20000
> Jan  1 00:06:25 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01c00000
> Jan  1 00:06:25 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01be0000
> Jan  1 00:06:25 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01bc0000
> Newly-erased block contained word 0x19850003 at offset 0x01ba0000
> Jan  1 Newly-erased block contained word 0x19850003 at offset 0x01b80000
> 00:06:Argh. No free space left for GC. nr_erasing_blocks is 0.
> nr_free_blocks is 0. (erasableempty: yes, erasingempty: yes,
> erasependingempty: yes)
> 26 rjtjffs2_reserve_space_gc of 196 bytes for garbage_collect_dnode failed: -28
>  Error garbage collecting node at 01b6db84!
> kerneNo space for garbage collection. Aborting GC thread
> l: Newly-erased block contained word 0x19850003 at offset 0x01ba0000
> Jan  1 00:06:26 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01b80000
> Jan  1 00:06:26 rjt kernel: Argh. No free space left for GC.
> nr_erasing_blocks is 0. nr_free_blocks is 0. (erasableempty: yes,
> erasingempty: yes, erasependingempty: yes)
> Jan  1 00:06:26 rjt kernel: jffs2_reserve_space_gc of 196 bytes for
> garbage_collect_dnode failed: -28
> Jan  1 00:06:26 rjt kernel: Error garbage collecting node at 01b6db84!
> Jan  1 00:06:26 rjt kernel: No space for garbage collection. Aborting GC thread
>
> I'd of course welcome any advice or further debugging suggestions.
>
> Thanks,
> - R
>
> ______________________________________________________
> Linux MTD discussion mailing list
> http://lists.infradead.org/mailman/listinfo/linux-mtd/

Re: JFFS2 errors on ppc-4xx with CFI NOR flash

[Ryan Thompson]

Hi Massimo,

The flash device is a Numonyx StrataFlash P33-65nm (1 Gbit version),
p/n PC28F00AP33EF.

I'll disable erase suspend and share my observations.

Thanks!
- R

On Thu, Mar 4, 2010 at 1:03 PM, massimo cirillo <maxcir@gmail.com> wrote:
> Please specify the complete part number of the flash device and I'll try to
> help you. As first attempt try to disable erase suspend feature in the flash
> driver.
>
> -----Messaggio originale-----
> Da: linux-mtd-bounces@lists.infradead.org
> [mailto:linux-mtd-bounces@lists.infradead.org] Per conto di Ryan Thompson
> Inviato: giovedì 4 marzo 2010 19.26
> A: linux-mtd@lists.infradead.org
> Oggetto: JFFS2 errors on ppc-4xx with CFI NOR flash
>
> Hi,
>
> We've been seeing errors on our ~32MiB jffs2 filesystem on a custom
> ppc-4xx board with a Numonyx 128MiB CFI NOR flash (128KiB erase
> blocks).
>
> The filesystem is mounted from /dev/mtd/modules, which is a symlink to
> /dev/mtdblock16, defined in the FDT as follows:
>
>            /* Modules (32128 KiB) */
>            partition@2e80000 {
>                reg = <0x2E80000 0x1F60000>;
>                label = "modules";
>            };
>
> When a significant amount of data (i.e., a few files over a few megs
> each) is written to the filesystem, we start seeing erase block
> errors, checksum failures, and garbage collection errors. However,
> these same filesystems have been in steady R&D use on this hardware
> and same 2.6.28 kernel for ~6 months without issue. Until recently our
> use case has only involved writing a small number of tiny files. We
> only started seeing errors when we began to write larger files.
>
> (Console output is at the end of this message.)
>
> I have been able to reproduce this problem on multiple systems with
> the following script (/mnt is defined in fstab(5) as jffs2 with
> noatime,noauto,rw):
>
> --------------------------
>
> #!/bin/sh
>
> umount /mnt && mount /mnt
> cd /mnt
> df /mnt
> while dd if=/dev/urandom of=`mktemp` count=512 2>/dev/null; do
>    sync
>    df /mnt | tail -1
> done
> echo "Filesystem full?"
> sync; sync
> df /mnt
> rm *.tmp
> sync; sync; sync
> df /mnt | tail -1
>
> --------------------------
>
> The errors tend to occur just after df shows approximately 52-55%
> (perhaps garbage collection starts around this time?)
>
> This occurs on at least 2.6.31. After the errors occur, the filesystem
> is unusable until I reboot the system (the errors just keep repeating,
> all reads and writes fail). However when the system is rebooted the
> filesystem seems to (silently) recover and be completely intact.
>
> We saw essentially the same errors on 2.6.28, but the kernel would
> panic. With 2.6.31, there is no panic, but a reboot is still necessary
> to restore operation.
>
> We use other partitions of the flash in block mode through mtdblockXX.
> As a test, I also formatted mtdblock16 (the jffs2 partition) as vfat.
> (Yes, I know how horrible this is!) With vfat, the above script filled
> the filesystem 10 times without issue (except for significantly
> reducing the lifespan of my flash part, I'm sure!) I additionally used
> a more complex version of the above script in some of my trials to
> store and verify the md5 sums of the random files written after the
> vfat filesystem was full; all files verified successfully.
>
> Here's the console output from one such incident:
>
> ----------- Console output --------------
> Newly-erased block contained word 0x19850003 at offset 0x01f20000
> Jan  1 00:06:15 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01f20000
> /dev/mtd/modules         32128     16916     15212  53% /mnt
> Node totlen on flash (0xffffffff) != totlen from node ref (0x00000044)
> Jan  1 00:06:16 rjt Node totlen on flash (0xffffffff) != totlen from
> node ref (0x00000044)
> kernel: Node totlen on flash (0xffffffff) != totlen from node ref
> (0x00000044)
> Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
> Jan  1 Node totlen on flash (0xffffffff) != totlen from node ref
> (0x00000244)
> Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
> Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
> Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
> Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
> Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
> 00:06:16 TerraceNode CRC ffffffff != calculated CRC f09e7845 for node
> at 01e162f0
> Q kernel: Node totlen on flash (0xffffffff) != totlen from node ref
> (0x00000044)
> Jan  1 00:06:16 rjtNewly-erased block contained word 0x19850003 at
> offset 0x01d20000
>  kerneNewly-erased block contained word 0x19850003 at offset 0x01d00000
> l: Node totlen on flash (0xffffffff) != totlen from node ref (0x00000244)
> Filesystem full?
> Jan  1 00:06:16 rjt last message 'kernel: Node totlen on flash
> (0xffffffff) != totlen from node ref
> Jan  1 00:06:16 rjt kernel: Node CRC ffffffff != calculated CRC
> f09e7845 for node at 01e162f0
> Jan  1 00:06:16 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01d20000
> Jan  1 00:06:16 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01d00000
> Filesystem           1K-blocks      Used Available Use% Mounted on
> /dev/mtd/modules         32128     17172     14956  53% /mnt
> rm: cannot remove '*.tmp': No such file or directory
> /dev/mtd/modules         32128     17172     14956  53% /mnt
> # Newly-erased block contained word 0x19850003 at offset 0x01ce0000
> Jan  1Newly-erased block contained word 0x19850003 at offset 0x01ca0000
>  00:06Newly-erased block contained word 0x19850003 at offset 0x01cc0000
> :20 Newly-erased block contained word 0x19850003 at offset 0x01c80000
> rjt kernel: Newly-erased block contained word 0x19850003 at offset
> 0x01ce0000
> Jan  1 00:06:20 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01ca0000
> Jan  1 00:06:20 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01cc0000
> Jan  1 00:06:20 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01c80000
> Newly-erased block contained word 0x19850003 at offset 0x01c60000
> Jan  1Newly-erased block contained word 0x19850003 at offset 0x01c40000
>  00:06Newly-erased block contained word 0x19850003 at offset 0x01c20000
> :25 rjNewly-erased block contained word 0x19850003 at offset 0x01c00000
> t Newly-erased block contained word 0x19850003 at offset 0x01be0000
> kernel:Newly-erased block contained word 0x19850003 at offset 0x01bc0000
>  Newly-erased block contained word 0x19850003 at offset 0x01c60000
> Jan  1 00:06:25 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01c40000
> Jan  1 00:06:25 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01c20000
> Jan  1 00:06:25 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01c00000
> Jan  1 00:06:25 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01be0000
> Jan  1 00:06:25 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01bc0000
> Newly-erased block contained word 0x19850003 at offset 0x01ba0000
> Jan  1 Newly-erased block contained word 0x19850003 at offset 0x01b80000
> 00:06:Argh. No free space left for GC. nr_erasing_blocks is 0.
> nr_free_blocks is 0. (erasableempty: yes, erasingempty: yes,
> erasependingempty: yes)
> 26 rjtjffs2_reserve_space_gc of 196 bytes for garbage_collect_dnode failed:
> -28
>  Error garbage collecting node at 01b6db84!
> kerneNo space for garbage collection. Aborting GC thread
> l: Newly-erased block contained word 0x19850003 at offset 0x01ba0000
> Jan  1 00:06:26 rjt kernel: Newly-erased block contained word
> 0x19850003 at offset 0x01b80000
> Jan  1 00:06:26 rjt kernel: Argh. No free space left for GC.
> nr_erasing_blocks is 0. nr_free_blocks is 0. (erasableempty: yes,
> erasingempty: yes, erasependingempty: yes)
> Jan  1 00:06:26 rjt kernel: jffs2_reserve_space_gc of 196 bytes for
> garbage_collect_dnode failed: -28
> Jan  1 00:06:26 rjt kernel: Error garbage collecting node at 01b6db84!
> Jan  1 00:06:26 rjt kernel: No space for garbage collection. Aborting GC
> thread
>
> I'd of course welcome any advice or further debugging suggestions.
>
> Thanks,
> - R
>
> ______________________________________________________
> Linux MTD discussion mailing list
> http://lists.infradead.org/mailman/listinfo/linux-mtd/
>
>

Re: JFFS2 errors on ppc-4xx with CFI NOR flash

[Ryan Thompson]

> On Thu, Mar 4, 2010 at 1:03 PM, massimo cirillo <maxcir@gmail.com> wrote:
>> As first attempt try to disable erase suspend feature in the flash
>> driver.

I have tried this against my 2.6.31 tree by uncommenting the following
in drivers/mtd/chips/cfi_cmdset_0001.c:40:

    #define CMDSET0001_DISABLE_ERASE_SUSPEND_ON_WRITE

Now my test output looks like the following. Note that it ran
successfully from 3% - 53%, which is right in the range where problems
tend to appear.

Filesystem           1K-blocks      Used Available Use% Mounted on
/dev/mtd/modules         32128      1032     31096   3% /mnt
[... snip 3 - 52%, no errors ...]
/dev/mtd/modules         32128     16668     15460  52% /mnt
/dev/mtd/modules         32128     16912     15216  53% /mnt
Jan  1 00:17:27 rjt kernel: Newly-erased block contained word 0x0 at
offset 0x0022a030
/dev/mtd/modules         32128     17308     14820  54% /mnt
/dev/mtd/modules         32128     17572     14556  55% /mnt
/dev/mtd/modules         32128     17836     14292  56% /mnt
/dev/mtd/modules         32128     18100     14028  56% /mnt
/dev/mtd/modules         32128     18368     13760  57% /mnt
/dev/mtd/modules         32128     18604     13524  58% /mnt
Jan  1 00:18:40 rjt kernel: Newly-erased block contained word 0x0 at
offset 0x01b2a010
/dev/mtd/modules         32128     18992     13136  59% /mnt
/dev/mtd/modules         32128     19260     12868  60% /mnt
/dev/mtd/modules         32128     19524     12604  61% /mnt
/dev/mtd/modules         32128     19788     12340  62% /mnt
/dev/mtd/modules         32128     20052     12076  62% /mnt
/dev/mtd/modules         32128     20316     11812  63% /mnt
/dev/mtd/modules         32128     20552     11576  64% /mnt
Jan  1 00:20:04 rjt kernel: Newly-erased block contained word 0x0 at
offset 0x013ca034
/dev/mtd/modules         32128     20944     11184  65% /mnt
/dev/mtd/modules         32128     21208     10920  66% /mnt
/dev/mtd/modules         32128     21476     10652  67% /mnt
/dev/mtd/modules         32128     21740     10388  68% /mnt
/dev/mtd/modules         32128     22004     10124  68% /mnt
/dev/mtd/modules         32128     22244      9884  69% /mnt
/dev/mtd/modules         32128     22504      9624  70% /mnt
/dev/mtd/modules         32128     22764      9364  71% /mnt
/dev/mtd/modules         32128     23032      9096  72% /mnt
/dev/mtd/modules         32128     23296      8832  73% /mnt
/dev/mtd/modules         32128     23564      8564  73% /mnt
/dev/mtd/modules         32128     23828      8300  74% /mnt
/dev/mtd/modules         32128     24092      8036  75% /mnt
/dev/mtd/modules         32128     24328      7800  76% /mnt
Jan  1 00:22:48 rjt kernel: Newly-erased block contained word 0x0 at
offset 0x0052a004
/dev/mtd/modules         32128     24716      7412  77% /mnt
Jan  1 00:23:02 rjt kernel: Newly-erased block contained word 0x0 at
offset 0x003ea034
/dev/mtd/modules         32128     25116      7012  78% /mnt
Jan  1 00:23:42 rjt kernel: Newly-erased block contained word 0x0 at
offset 0x0006a028
/dev/mtd/modules         32128     25492      6636  79% /mnt
Jan  1 00:24:03 rjt kernel: Newly-erased block contained word 0x0 at
offset 0x01dc9fb8
Jan  1 00:24:12 rjt kernel: f0000000.flash: block erase error: (status timeout)
Jan  1 00:24:12 rjt kernel: Erase at 0x01da0000 failed immediately: errno -62
Jan  1 00:24:27 rjt kernel: Newly-erased block contained word 0x0 at
offset 0x01c6a004
Jan  1 00:24:36 rjt kernel: f0000000.flash: block erase error: (status timeout)
Jan  1 00:24:36 rjt kernel: Erase at 0x01c40000 failed immediately: errno -62
/dev/mtd/modules         32128     26268      5860  82% /mnt
/dev/mtd/modules         32128     26528      5600  83% /mnt
Jan  1 00:25:33 rjt kernel: Newly-erased block contained word 0x0 at
offset 0x017aa034
Jan  1 00:25:41 rjt kernel: f0000000.flash: block erase error: (status timeout)
Jan  1 00:25:41 rjt kernel: Erase at 0x01780000 failed immediately: errno -62
Jan  1 00:25:45 rjt kernel: Newly-erased block contained word 0x0 at
offset 0x0176a024
Jan  1 00:25:54 rjt kernel: f0000000.flash: block erase error: (status timeout)
Jan  1 00:25:54 rjt kernel: Erase at 0x01740000 failed immediately: errno -62
Jan  1 00:26:14 rjt kernel: Newly-erased block contained word 0x0 at
offset 0x0154a048
Jan  1 00:26:23 rjt kernel: f0000000.flash: block erase error: (status timeout)
Jan  1 00:26:23 rjt kernel: Erase at 0x01520000 failed immediately: errno -62
Jan  1 00:26:44 rjt kernel: Newly-erased block contained word 0x0 at
offset 0x0150a024
Jan  1 00:26:53 rjt kernel: f0000000.flash: block erase error: (status timeout)
Jan  1 00:26:53 rjt kernel: Erase at 0x014e0000 failed immediately: errno -62
Jan  1 00:27:18 rjt kernel: Newly-erased block contained word 0x0 at
offset 0x0140738c
Jan  1 00:27:27 rjt kernel: f0000000.flash: block erase error: (status timeout)
Jan  1 00:27:27 rjt kernel: Erase at 0x013e0000 failed immediately: errno -62
/dev/mtd/modules         32128     28076      4052  87% /mnt
Jan  1 00:28:10 rjt kernel: Newly-erased block contained word 0x0 at
offset 0x00f6a048
Jan  1 00:28:18 rjt kernel: f0000000.flash: block erase error: (status timeout)
Jan  1 00:28:18 rjt kernel: Erase at 0x00f40000 failed immediately: errno -62
/dev/mtd/modules         32128     28584      3544  89% /mnt
Jan  1 00:28:42 rjt kernel: Newly-erased block contained word 0x0 at
offset 0x00d2a040
Jan  1 00:28:51 rjt kernel: f0000000.flash: block erase error: (status timeout)
Jan  1 00:28:51 rjt kernel: Erase at 0x00d00000 failed immediately: errno -62
Jan  1 00:29:04 rjt kernel: Newly-erased block contained word 0x0 at
offset 0x00cca02c
Jan  1 00:29:12 rjt kernel: f0000000.flash: block erase error: (status timeout)
Jan  1 00:29:12 rjt kernel: Erase at 0x00ce0000 failed immediately: errno -62
Jan  1 00:29:42 rjt kernel: Newly-erased block contained word 0x0 at
offset 0x00aca038
Jan  1 00:29:51 rjt kernel: f0000000.flash: block erase error: (status timeout)
Jan  1 00:29:51 rjt kernel: Erase at 0x00aa0000 failed immediately: errno -62
Jan  1 00:30:02 rjt kernel: Newly-erased block contained word 0x0 at
offset 0x0096a010
Jan  1 00:30:11 rjt kernel: f0000000.flash: block erase error: (status timeout)
Jan  1 00:30:11 rjt kernel: Erase at 0x00940000 failed immediately: errno -62
/dev/mtd/modules         32128     29872      2256  93% /mnt

The errors continued until the filesystem actually reported 100% full
and my script terminated. The entire 3%-100% operation took about 21
minutes for <32MiB, and was definitely much slower towards the end
with all the errors.

- R

Re: JFFS2 errors on ppc-4xx with CFI NOR flash

[massimo cirillo]

I suppose you don't have CONFIG_MTD_XIP enabled.
So in order to completely disable the suspend,
please in chip_ready() function just after "case FL_ERASING:"
(line 775) put the line "goto sleep;" and repeat your test.
Let me know.

2010/3/4 Ryan Thompson <i@ry.ca>:
>> On Thu, Mar 4, 2010 at 1:03 PM, massimo cirillo <maxcir@gmail.com> wrote:
>>> As first attempt try to disable erase suspend feature in the flash
>>> driver.
>
> I have tried this against my 2.6.31 tree by uncommenting the following
> in drivers/mtd/chips/cfi_cmdset_0001.c:40:
>
>    #define CMDSET0001_DISABLE_ERASE_SUSPEND_ON_WRITE
>
> Now my test output looks like the following. Note that it ran
> successfully from 3% - 53%, which is right in the range where problems
> tend to appear.
>
> Filesystem           1K-blocks      Used Available Use% Mounted on
> /dev/mtd/modules         32128      1032     31096   3% /mnt
> [... snip 3 - 52%, no errors ...]
> /dev/mtd/modules         32128     16668     15460  52% /mnt
> /dev/mtd/modules         32128     16912     15216  53% /mnt
> Jan  1 00:17:27 rjt kernel: Newly-erased block contained word 0x0 at
> offset 0x0022a030
> /dev/mtd/modules         32128     17308     14820  54% /mnt
> /dev/mtd/modules         32128     17572     14556  55% /mnt
> /dev/mtd/modules         32128     17836     14292  56% /mnt
> /dev/mtd/modules         32128     18100     14028  56% /mnt
> /dev/mtd/modules         32128     18368     13760  57% /mnt
> /dev/mtd/modules         32128     18604     13524  58% /mnt
> Jan  1 00:18:40 rjt kernel: Newly-erased block contained word 0x0 at
> offset 0x01b2a010
> /dev/mtd/modules         32128     18992     13136  59% /mnt
> /dev/mtd/modules         32128     19260     12868  60% /mnt
> /dev/mtd/modules         32128     19524     12604  61% /mnt
> /dev/mtd/modules         32128     19788     12340  62% /mnt
> /dev/mtd/modules         32128     20052     12076  62% /mnt
> /dev/mtd/modules         32128     20316     11812  63% /mnt
> /dev/mtd/modules         32128     20552     11576  64% /mnt
> Jan  1 00:20:04 rjt kernel: Newly-erased block contained word 0x0 at
> offset 0x013ca034
> /dev/mtd/modules         32128     20944     11184  65% /mnt
> /dev/mtd/modules         32128     21208     10920  66% /mnt
> /dev/mtd/modules         32128     21476     10652  67% /mnt
> /dev/mtd/modules         32128     21740     10388  68% /mnt
> /dev/mtd/modules         32128     22004     10124  68% /mnt
> /dev/mtd/modules         32128     22244      9884  69% /mnt
> /dev/mtd/modules         32128     22504      9624  70% /mnt
> /dev/mtd/modules         32128     22764      9364  71% /mnt
> /dev/mtd/modules         32128     23032      9096  72% /mnt
> /dev/mtd/modules         32128     23296      8832  73% /mnt
> /dev/mtd/modules         32128     23564      8564  73% /mnt
> /dev/mtd/modules         32128     23828      8300  74% /mnt
> /dev/mtd/modules         32128     24092      8036  75% /mnt
> /dev/mtd/modules         32128     24328      7800  76% /mnt
> Jan  1 00:22:48 rjt kernel: Newly-erased block contained word 0x0 at
> offset 0x0052a004
> /dev/mtd/modules         32128     24716      7412  77% /mnt
> Jan  1 00:23:02 rjt kernel: Newly-erased block contained word 0x0 at
> offset 0x003ea034
> /dev/mtd/modules         32128     25116      7012  78% /mnt
> Jan  1 00:23:42 rjt kernel: Newly-erased block contained word 0x0 at
> offset 0x0006a028
> /dev/mtd/modules         32128     25492      6636  79% /mnt
> Jan  1 00:24:03 rjt kernel: Newly-erased block contained word 0x0 at
> offset 0x01dc9fb8
> Jan  1 00:24:12 rjt kernel: f0000000.flash: block erase error: (status timeout)
> Jan  1 00:24:12 rjt kernel: Erase at 0x01da0000 failed immediately: errno -62
> Jan  1 00:24:27 rjt kernel: Newly-erased block contained word 0x0 at
> offset 0x01c6a004
> Jan  1 00:24:36 rjt kernel: f0000000.flash: block erase error: (status timeout)
> Jan  1 00:24:36 rjt kernel: Erase at 0x01c40000 failed immediately: errno -62
> /dev/mtd/modules         32128     26268      5860  82% /mnt
> /dev/mtd/modules         32128     26528      5600  83% /mnt
> Jan  1 00:25:33 rjt kernel: Newly-erased block contained word 0x0 at
> offset 0x017aa034
> Jan  1 00:25:41 rjt kernel: f0000000.flash: block erase error: (status timeout)
> Jan  1 00:25:41 rjt kernel: Erase at 0x01780000 failed immediately: errno -62
> Jan  1 00:25:45 rjt kernel: Newly-erased block contained word 0x0 at
> offset 0x0176a024
> Jan  1 00:25:54 rjt kernel: f0000000.flash: block erase error: (status timeout)
> Jan  1 00:25:54 rjt kernel: Erase at 0x01740000 failed immediately: errno -62
> Jan  1 00:26:14 rjt kernel: Newly-erased block contained word 0x0 at
> offset 0x0154a048
> Jan  1 00:26:23 rjt kernel: f0000000.flash: block erase error: (status timeout)
> Jan  1 00:26:23 rjt kernel: Erase at 0x01520000 failed immediately: errno -62
> Jan  1 00:26:44 rjt kernel: Newly-erased block contained word 0x0 at
> offset 0x0150a024
> Jan  1 00:26:53 rjt kernel: f0000000.flash: block erase error: (status timeout)
> Jan  1 00:26:53 rjt kernel: Erase at 0x014e0000 failed immediately: errno -62
> Jan  1 00:27:18 rjt kernel: Newly-erased block contained word 0x0 at
> offset 0x0140738c
> Jan  1 00:27:27 rjt kernel: f0000000.flash: block erase error: (status timeout)
> Jan  1 00:27:27 rjt kernel: Erase at 0x013e0000 failed immediately: errno -62
> /dev/mtd/modules         32128     28076      4052  87% /mnt
> Jan  1 00:28:10 rjt kernel: Newly-erased block contained word 0x0 at
> offset 0x00f6a048
> Jan  1 00:28:18 rjt kernel: f0000000.flash: block erase error: (status timeout)
> Jan  1 00:28:18 rjt kernel: Erase at 0x00f40000 failed immediately: errno -62
> /dev/mtd/modules         32128     28584      3544  89% /mnt
> Jan  1 00:28:42 rjt kernel: Newly-erased block contained word 0x0 at
> offset 0x00d2a040
> Jan  1 00:28:51 rjt kernel: f0000000.flash: block erase error: (status timeout)
> Jan  1 00:28:51 rjt kernel: Erase at 0x00d00000 failed immediately: errno -62
> Jan  1 00:29:04 rjt kernel: Newly-erased block contained word 0x0 at
> offset 0x00cca02c
> Jan  1 00:29:12 rjt kernel: f0000000.flash: block erase error: (status timeout)
> Jan  1 00:29:12 rjt kernel: Erase at 0x00ce0000 failed immediately: errno -62
> Jan  1 00:29:42 rjt kernel: Newly-erased block contained word 0x0 at
> offset 0x00aca038
> Jan  1 00:29:51 rjt kernel: f0000000.flash: block erase error: (status timeout)
> Jan  1 00:29:51 rjt kernel: Erase at 0x00aa0000 failed immediately: errno -62
> Jan  1 00:30:02 rjt kernel: Newly-erased block contained word 0x0 at
> offset 0x0096a010
> Jan  1 00:30:11 rjt kernel: f0000000.flash: block erase error: (status timeout)
> Jan  1 00:30:11 rjt kernel: Erase at 0x00940000 failed immediately: errno -62
> /dev/mtd/modules         32128     29872      2256  93% /mnt
>
> The errors continued until the filesystem actually reported 100% full
> and my script terminated. The entire 3%-100% operation took about 21
> minutes for <32MiB, and was definitely much slower towards the end
> with all the errors.
>
> - R
>

Re: JFFS2 errors on ppc-4xx with CFI NOR flash

[Ryan Thompson]

On Fri, Mar 5, 2010 at 3:56 AM, massimo cirillo <maxcir@gmail.com> wrote:
> I suppose you don't have CONFIG_MTD_XIP enabled.
> So in order to completely disable the suspend,
> please in chip_ready() function just after "case FL_ERASING:"
> (line 775) put the line "goto sleep;" and repeat your test.
> Let me know.

By skipping the FL_ERASING case as you suggested, my test now
completes successfully without any INFO-or-higher kernel messages.

However, it still takes a very long time. The initial files are
written out quickly (subjectively, performance seems similar to raw
mtd speed). However, after 50% or so, performance begins to degrade
dramatically. At 65%, a 256KiB file takes 11 sec to write. At 75%, 20
sec. 90%, 38 sec. 95%, 77 sec. 99%, 121 sec. The entire test took 28.4
minutes to go from 3%-100% on the ~32MiB partition.

Performance seems somewhat consistent with my previous result:

> 2010/3/4 Ryan Thompson <i@ry.ca>:
>> The errors continued until the filesystem actually reported 100% full
>> and my script terminated. The entire 3%-100% operation took about 21
>> minutes for <32MiB, and was definitely much slower towards the end
>> with all the errors.

I've done a flash_eraseall -j followed by a reboot before each run.

I also benchmarked the mtdblock performance without JFFS2 (also
getting input from urandom):

# time dd if=/dev/urandom of=/dev/mtdblock16
dd: writing '/dev/mtdblock16': No space left on device
64257+0 records in
64256+0 records out
Command exited with non-zero status 1
real	5m 30.17s
user	0m 0.08s
sys	1m 2.66s
# perl -le 'printf("bytes written = 0x%08x\n", 64256 * 512);'
bytes written = 0x01f60000
# grep modules /proc/mtd
mtd16: 01f60000 00020000 "modules"

- R

Re: JFFS2 errors on ppc-4xx with CFI NOR flash

[Ryan Thompson]

[-- Attachment #1: Type: text/plain, Size: 2210 bytes --]

I also created the attached gnuplot graph showing the time taken to
write 128KiB files versus the filesystem utilization. Note that the
underlying partition size is 32128KiB.

In case attachments don't work on linux-mtd, the graph is also hosted
at http://ry.ca/clients/jffs2-128KiB.png

- R

On Fri, Mar 5, 2010 at 11:36 AM, Ryan Thompson <i@ry.ca> wrote:
> On Fri, Mar 5, 2010 at 3:56 AM, massimo cirillo <maxcir@gmail.com> wrote:
>> I suppose you don't have CONFIG_MTD_XIP enabled.
>> So in order to completely disable the suspend,
>> please in chip_ready() function just after "case FL_ERASING:"
>> (line 775) put the line "goto sleep;" and repeat your test.
>> Let me know.
>
> By skipping the FL_ERASING case as you suggested, my test now
> completes successfully without any INFO-or-higher kernel messages.
>
> However, it still takes a very long time. The initial files are
> written out quickly (subjectively, performance seems similar to raw
> mtd speed). However, after 50% or so, performance begins to degrade
> dramatically. At 65%, a 256KiB file takes 11 sec to write. At 75%, 20
> sec. 90%, 38 sec. 95%, 77 sec. 99%, 121 sec. The entire test took 28.4
> minutes to go from 3%-100% on the ~32MiB partition.
>
> Performance seems somewhat consistent with my previous result:
>
>> 2010/3/4 Ryan Thompson <i@ry.ca>:
>>> The errors continued until the filesystem actually reported 100% full
>>> and my script terminated. The entire 3%-100% operation took about 21
>>> minutes for <32MiB, and was definitely much slower towards the end
>>> with all the errors.
>
> I've done a flash_eraseall -j followed by a reboot before each run.
>
> I also benchmarked the mtdblock performance without JFFS2 (also
> getting input from urandom):
>
> # time dd if=/dev/urandom of=/dev/mtdblock16
> dd: writing '/dev/mtdblock16': No space left on device
> 64257+0 records in
> 64256+0 records out
> Command exited with non-zero status 1
> real    5m 30.17s
> user    0m 0.08s
> sys     1m 2.66s
> # perl -le 'printf("bytes written = 0x%08x\n", 64256 * 512);'
> bytes written = 0x01f60000
> # grep modules /proc/mtd
> mtd16: 01f60000 00020000 "modules"
>
> - R
>

[-- Attachment #2: jffs2-128KiB.png --]
[-- Type: image/png, Size: 25497 bytes --]

Re: JFFS2 errors on ppc-4xx with CFI NOR flash

[Joakim Tjernlund]

>
> I also created the attached gnuplot graph showing the time taken to
> write 128KiB files versus the filesystem utilization. Note that the
> underlying partition size is 32128KiB.
>
> In case attachments don't work on linux-mtd, the graph is also hosted
> at http://ry.ca/clients/jffs2-128KiB.png

I am guessing the flash is busy erasing blocks so writes have to wait.
What if you pause your test when it starts to get slow for a few mins
and continue?

it is strange though that erase suspend isn't working for you. I have
no such problems and I use numonyx too, but not this exact part(don't have
part info available ATM)

>
> - R
>
> On Fri, Mar 5, 2010 at 11:36 AM, Ryan Thompson <i@ry.ca> wrote:
> > On Fri, Mar 5, 2010 at 3:56 AM, massimo cirillo <maxcir@gmail.com> wrote:
> >> I suppose you don't have CONFIG_MTD_XIP enabled.
> >> So in order to completely disable the suspend,
> >> please in chip_ready() function just after "case FL_ERASING:"
> >> (line 775) put the line "goto sleep;" and repeat your test.
> >> Let me know.
> >
> > By skipping the FL_ERASING case as you suggested, my test now
> > completes successfully without any INFO-or-higher kernel messages.
> >
> > However, it still takes a very long time. The initial files are
> > written out quickly (subjectively, performance seems similar to raw
> > mtd speed). However, after 50% or so, performance begins to degrade
> > dramatically. At 65%, a 256KiB file takes 11 sec to write. At 75%, 20
> > sec. 90%, 38 sec. 95%, 77 sec. 99%, 121 sec. The entire test took 28.4
> > minutes to go from 3%-100% on the ~32MiB partition.
> >
> > Performance seems somewhat consistent with my previous result:
> >
> >> 2010/3/4 Ryan Thompson <i@ry.ca>:
> >>> The errors continued until the filesystem actually reported 100% full
> >>> and my script terminated. The entire 3%-100% operation took about 21
> >>> minutes for <32MiB, and was definitely much slower towards the end
> >>> with all the errors.
> >
> > I've done a flash_eraseall -j followed by a reboot before each run.
> >
> > I also benchmarked the mtdblock performance without JFFS2 (also
> > getting input from urandom):
> >
> > # time dd if=/dev/urandom of=/dev/mtdblock16
> > dd: writing '/dev/mtdblock16': No space left on device
> > 64257+0 records in
> > 64256+0 records out
> > Command exited with non-zero status 1
> > real    5m 30.17s
> > user    0m 0.08s
> > sys     1m 2.66s
> > # perl -le 'printf("bytes written = 0x%08x\n", 64256 * 512);'
> > bytes written = 0x01f60000
> > # grep modules /proc/mtd
> > mtd16: 01f60000 00020000 "modules"
> >
> > - R
> >
> [attachment "jffs2-128KiB.png" deleted by Joakim Tjernlund/Transmode]
> ______________________________________________________
> Linux MTD discussion mailing list
> http://lists.infradead.org/mailman/listinfo/linux-mtd/

Re: JFFS2 errors on ppc-4xx with CFI NOR flash

[massimo cirillo]

Ryan,
the reason of bad performances is the disabling of erase suspend on
every request (read and write), so when the garbage starts to free some
blocks with erase, this erase cannot be suspended.
If the performance is a problem for you, I should investigate about the
flash device you are using.
I'll write to you in private.

2010/3/6 Joakim Tjernlund <joakim.tjernlund@transmode.se>:
>
>>
>> I also created the attached gnuplot graph showing the time taken to
>> write 128KiB files versus the filesystem utilization. Note that the
>> underlying partition size is 32128KiB.
>>
>> In case attachments don't work on linux-mtd, the graph is also hosted
>> at http://ry.ca/clients/jffs2-128KiB.png
>
> I am guessing the flash is busy erasing blocks so writes have to wait.
> What if you pause your test when it starts to get slow for a few mins
> and continue?
>
> it is strange though that erase suspend isn't working for you. I have
> no such problems and I use numonyx too, but not this exact part(don't have
> part info available ATM)
>
>>
>> - R
>>
>> On Fri, Mar 5, 2010 at 11:36 AM, Ryan Thompson <i@ry.ca> wrote:
>> > On Fri, Mar 5, 2010 at 3:56 AM, massimo cirillo <maxcir@gmail.com> wrote:
>> >> I suppose you don't have CONFIG_MTD_XIP enabled.
>> >> So in order to completely disable the suspend,
>> >> please in chip_ready() function just after "case FL_ERASING:"
>> >> (line 775) put the line "goto sleep;" and repeat your test.
>> >> Let me know.
>> >
>> > By skipping the FL_ERASING case as you suggested, my test now
>> > completes successfully without any INFO-or-higher kernel messages.
>> >
>> > However, it still takes a very long time. The initial files are
>> > written out quickly (subjectively, performance seems similar to raw
>> > mtd speed). However, after 50% or so, performance begins to degrade
>> > dramatically. At 65%, a 256KiB file takes 11 sec to write. At 75%, 20
>> > sec. 90%, 38 sec. 95%, 77 sec. 99%, 121 sec. The entire test took 28.4
>> > minutes to go from 3%-100% on the ~32MiB partition.
>> >
>> > Performance seems somewhat consistent with my previous result:
>> >
>> >> 2010/3/4 Ryan Thompson <i@ry.ca>:
>> >>> The errors continued until the filesystem actually reported 100% full
>> >>> and my script terminated. The entire 3%-100% operation took about 21
>> >>> minutes for <32MiB, and was definitely much slower towards the end
>> >>> with all the errors.
>> >
>> > I've done a flash_eraseall -j followed by a reboot before each run.
>> >
>> > I also benchmarked the mtdblock performance without JFFS2 (also
>> > getting input from urandom):
>> >
>> > # time dd if=/dev/urandom of=/dev/mtdblock16
>> > dd: writing '/dev/mtdblock16': No space left on device
>> > 64257+0 records in
>> > 64256+0 records out
>> > Command exited with non-zero status 1
>> > real    5m 30.17s
>> > user    0m 0.08s
>> > sys     1m 2.66s
>> > # perl -le 'printf("bytes written = 0x%08x\n", 64256 * 512);'
>> > bytes written = 0x01f60000
>> > # grep modules /proc/mtd
>> > mtd16: 01f60000 00020000 "modules"
>> >
>> > - R
>> >
>> [attachment "jffs2-128KiB.png" deleted by Joakim Tjernlund/Transmode]
>> ______________________________________________________
>> Linux MTD discussion mailing list
>> http://lists.infradead.org/mailman/listinfo/linux-mtd/
>
>

Re: JFFS2 errors on ppc-4xx with CFI NOR flash

[Ryan Thompson]

Thank you Massimo. I received your private email and will respond from
my company address with the info you've asked for.

- R

On Mon, Mar 8, 2010 at 5:24 AM, massimo cirillo <maxcir@gmail.com> wrote:
> Ryan,
> the reason of bad performances is the disabling of erase suspend on
> every request (read and write), so when the garbage starts to free some
> blocks with erase, this erase cannot be suspended.
> If the performance is a problem for you, I should investigate about the
> flash device you are using.
> I'll write to you in private.
>
> 2010/3/6 Joakim Tjernlund <joakim.tjernlund@transmode.se>:
>>
>>>
>>> I also created the attached gnuplot graph showing the time taken to
>>> write 128KiB files versus the filesystem utilization. Note that the
>>> underlying partition size is 32128KiB.
>>>
>>> In case attachments don't work on linux-mtd, the graph is also hosted
>>> at http://ry.ca/clients/jffs2-128KiB.png
>>
>> I am guessing the flash is busy erasing blocks so writes have to wait.
>> What if you pause your test when it starts to get slow for a few mins
>> and continue?
>>
>> it is strange though that erase suspend isn't working for you. I have
>> no such problems and I use numonyx too, but not this exact part(don't have
>> part info available ATM)
>>
>>>
>>> - R
>>>
>>> On Fri, Mar 5, 2010 at 11:36 AM, Ryan Thompson <i@ry.ca> wrote:
>>> > On Fri, Mar 5, 2010 at 3:56 AM, massimo cirillo <maxcir@gmail.com> wrote:
>>> >> I suppose you don't have CONFIG_MTD_XIP enabled.
>>> >> So in order to completely disable the suspend,
>>> >> please in chip_ready() function just after "case FL_ERASING:"
>>> >> (line 775) put the line "goto sleep;" and repeat your test.
>>> >> Let me know.
>>> >
>>> > By skipping the FL_ERASING case as you suggested, my test now
>>> > completes successfully without any INFO-or-higher kernel messages.
>>> >
>>> > However, it still takes a very long time. The initial files are
>>> > written out quickly (subjectively, performance seems similar to raw
>>> > mtd speed). However, after 50% or so, performance begins to degrade
>>> > dramatically. At 65%, a 256KiB file takes 11 sec to write. At 75%, 20
>>> > sec. 90%, 38 sec. 95%, 77 sec. 99%, 121 sec. The entire test took 28.4
>>> > minutes to go from 3%-100% on the ~32MiB partition.
>>> >
>>> > Performance seems somewhat consistent with my previous result:
>>> >
>>> >> 2010/3/4 Ryan Thompson <i@ry.ca>:
>>> >>> The errors continued until the filesystem actually reported 100% full
>>> >>> and my script terminated. The entire 3%-100% operation took about 21
>>> >>> minutes for <32MiB, and was definitely much slower towards the end
>>> >>> with all the errors.
>>> >
>>> > I've done a flash_eraseall -j followed by a reboot before each run.
>>> >
>>> > I also benchmarked the mtdblock performance without JFFS2 (also
>>> > getting input from urandom):
>>> >
>>> > # time dd if=/dev/urandom of=/dev/mtdblock16
>>> > dd: writing '/dev/mtdblock16': No space left on device
>>> > 64257+0 records in
>>> > 64256+0 records out
>>> > Command exited with non-zero status 1
>>> > real    5m 30.17s
>>> > user    0m 0.08s
>>> > sys     1m 2.66s
>>> > # perl -le 'printf("bytes written = 0x%08x\n", 64256 * 512);'
>>> > bytes written = 0x01f60000
>>> > # grep modules /proc/mtd
>>> > mtd16: 01f60000 00020000 "modules"
>>> >
>>> > - R
>>> >
>>> [attachment "jffs2-128KiB.png" deleted by Joakim Tjernlund/Transmode]
>>> ______________________________________________________
>>> Linux MTD discussion mailing list
>>> http://lists.infradead.org/mailman/listinfo/linux-mtd/
>>
>>
>