JFFS2 oops when writing to two partitions simultaneously

JFFS2 oops when writing to two partitions simultaneously

[Orjan Friberg]

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

Hi,

I'm in the process of narrowing down an oops that happens when doing a

   while :; do dd if=/dev/zero of=file bs=800 count=1; done

on two different JFFS2 partitions simultaneously.

The oops happens in crc32_le, coming from jffs2_write_inode_range 
(jffs2_oops attachment).


Sometimes it's sufficient to scp a file to the root partition 
immediately after boot to trigger the oops, possibly because there are 
gc threads running on both mtd partitions because of previous power 
cycles (jffs2_oops_gc attachment).

In addition to these oops, on occasion I get decompress errors instead 
which prevent me from writing to the affected partition.  In that case, 
unmounting the partition, remounting it and removing the offending file 
gets things back into working order.  That situation is harder to 
reproduce, but I thought I'd at least mention it.


I'd appreciate pointers on what to look at next.  More details below.

Thanks,
Orjan



The board is a BeagleBoard-like board (OMAP 3730/Cortex-A8) with a 256 
MB Micron NAND.  We use a slightly old kernel, 2.6.32 and the 
CodeSourcery Lite 2009q1 compiler (gcc 4.3.3).  JFFS2 kernel options:

CONFIG_JFFS2_FS=y
CONFIG_JFFS2_FS_DEBUG=0
CONFIG_JFFS2_FS_WRITEBUFFER=y
# CONFIG_JFFS2_FS_WBUF_VERIFY is not set
CONFIG_JFFS2_SUMMARY=y
# CONFIG_JFFS2_FS_XATTR is not set
CONFIG_JFFS2_COMPRESSION_OPTIONS=y
CONFIG_JFFS2_ZLIB=y
CONFIG_JFFS2_LZO=y
CONFIG_JFFS2_RTIME=y
CONFIG_JFFS2_RUBIN=y
# CONFIG_JFFS2_CMODE_NONE is not set
# CONFIG_JFFS2_CMODE_PRIORITY is not set
# CONFIG_JFFS2_CMODE_SIZE is not set
CONFIG_JFFS2_CMODE_FAVOURLZO=y

/proc/mtd:

dev:    size   erasesize  name
mtd0: 001e0000 00020000 "U-Boot"
mtd1: 00020000 00020000 "U-Boot Env"
mtd2: 01000000 00020000 "FlatFrog"
mtd3: 00400000 00020000 "Kernel"
mtd4: 0ea00000 00020000 "File System"


-- 
Orjan Friberg
FlatFrog Laboratories AB

[-- Attachment #2: jffs2_oops --]
[-- Type: text/plain, Size: 4618 bytes --]

[   81.200805] Unable to handle kernel NULL pointer dereference at virtual address 00000000
[   81.217529] pgd = ce13c000
[   81.220855] [00000000] *pgd=8e172031, *pte=00000000, *ppte=00000000
[   81.236480] Internal error: Oops: 17 [#1] PREEMPT
[   81.241210] last sysfs file: /sys/kernel/uevent_seqnum
[   81.246368] Modules linked in: ftdi_sio usbserial
[   81.251129] CPU: 0    Not tainted  (2.6.32 #6)
[   81.255584] PC is at crc32_le+0x6c/0xf4
[   81.259460] LR is at jffs2_write_inode_range+0x2a0/0x420
[   81.264801] pc : [<c0211f28>]    lr : [<c01ae930>]    psr: 20000013
[   81.264801] sp : ce24bcd0  ip : 00000001  fp : ce11f840
[   81.276336] r10: 0000000c  r9 : ce5231d0  r8 : fffffffc
[   81.281585] r7 : 00000002  r6 : 00000000  r5 : c03fcf9c  r4 : 00000000
[   81.288146] r3 : 00000000  r2 : 00000008  r1 : 00000000  r0 : 00000000
[   81.294677] Flags: nzCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment user
[   81.301849] Control: 10c5387d  Table: 8e13c019  DAC: 00000015
[   81.307617] Process dd (pid: 5270, stack limit = 0xce24a2f0)
[   81.313323] Stack: (0xce24bcd0 to 0xce24c000)
[   81.317687] bcc0:                                     00000000 00000002 00000003 00000000
[   81.325897] bce0: 00000000 c01ae930 ce24bd1c ce24bd18 00000000 00000008 00000000 00000000
[   81.334136] bd00: 00000000 00000002 cdca7000 ce1a8800 00000000 00000000 00000008 00000320
[   81.342346] bd20: 0001326c 00000000 00000320 00000000 ce11f840 ce523208 00000000 c07754e0
[   81.350555] bd40: 00000320 00000000 ce1a8800 c01a8ac4 00000000 00000320 ce24bd74 ffffffff
[   81.358764] bd60: 00000000 00000320 00000000 00000000 00000320 00000000 00000320 00000320
[   81.367004] bd80: 00000000 00000000 00000000 00000320 00000000 00000000 ce5232b0 c0097d1c
[   81.375213] bda0: 00000320 00000320 c07754e0 ce523208 ce24a000 cebf4140 ce5232b0 00001000
[   81.383422] bdc0: 00000000 c03efe38 ce24bf40 00000001 00000000 00000320 ce523208 c07754e0
[   81.391632] bde0: 00000320 00000320 00000000 00000320 ce523208 00000000 00000000 00000000
[   81.399871] be00: 00000000 c009846c 00000000 00000000 ce24bf00 00000320 00000000 00000000
[   81.408081] be20: 00000002 ce24bf00 ce24bf40 ce24beb0 cebf4140 ce5232b0 00000320 00000001
[   81.416290] be40: ce24a000 ce523278 000ad008 c03dd658 22222222 00000320 22222222 ce523278
[   81.424530] be60: ce24bf40 ce24beb0 00000001 00000000 cebf4140 00000000 000ad008 c009851c
[   81.432739] be80: ce24beb0 ce24bf40 00000000 00000000 ce24beb0 cebf4140 ce24bf80 ce24a000
[   81.440948] bea0: 000aad28 c00bf584 00000000 00000000 00020242 ce1ae000 00000000 00000001
[   81.449157] bec0: ffffffff cebf4140 00000000 00000000 00000000 00000000 ce12d6c0 00020241
[   81.457397] bee0: 00000000 00000000 00000200 ce12d6c0 c0077028 ce24bef4 ce24bef4 00000004
[   81.465606] bf00: 00000000 00000000 000aad28 00000300 00000000 00000000 00000320 00100073
[   81.473815] bf20: 000ad000 ce24a000 000ce000 00000000 00000002 ceb450e0 ce4b0618 00000001
[   81.482025] bf40: 000ad008 00000320 cebf4140 000ad008 ce24bf80 00000320 00000320 c00c01c8
[   81.490264] bf60: cebf4140 000ad008 00000000 00000000 cebf4140 00000320 000ad008 c00c036c
[   81.498474] bf80: 00000000 00000000 00000320 00000000 00000320 00000001 000ad008 00000004
[   81.506683] bfa0: c00390c4 c0038f40 00000320 00000001 00000001 000ad008 00000320 000acd34
[   81.514923] bfc0: 00000320 00000001 000ad008 00000004 00000320 000ad008 000aad28 000ad008
[   81.523132] bfe0: 4001e3e0 bece4b60 00010e34 40188abc 60000010 00000001 00000000 00000000
[   81.531372] [<c0211f28>] (crc32_le+0x6c/0xf4) from [<c01ae930>] (jffs2_write_inode_range+0x2a0/0x420)
[   81.540618] [<c01ae930>] (jffs2_write_inode_range+0x2a0/0x420) from [<c01a8ac4>] (jffs2_write_end+0x190/0x2d4)
[   81.550689] [<c01a8ac4>] (jffs2_write_end+0x190/0x2d4) from [<c0097d1c>] (generic_file_buffered_write+0x180/0x264)
[   81.561096] [<c0097d1c>] (generic_file_buffered_write+0x180/0x264) from [<c009846c>] (__generic_file_aio_write+0x468/0x4b0)
[   81.572265] [<c009846c>] (__generic_file_aio_write+0x468/0x4b0) from [<c009851c>] (generic_file_aio_write+0x68/0xc4)
[   81.582855] [<c009851c>] (generic_file_aio_write+0x68/0xc4) from [<c00bf584>] (do_sync_write+0xac/0xfc)
[   81.592285] [<c00bf584>] (do_sync_write+0xac/0xfc) from [<c00c01c8>] (vfs_write+0xac/0x1a4)
[   81.600677] [<c00c01c8>] (vfs_write+0xac/0x1a4) from [<c00c036c>] (sys_write+0x3c/0x68)
[   81.608734] [<c00c036c>] (sys_write+0x3c/0x68) from [<c0038f40>] (ret_fast_syscall+0x0/0x2c)
[   81.617218] Code: e2448004 e3a01000 e1a0c007 ea00000e (e7942001) 
[   82.040069] ---[ end trace 6a60d817de90299e ]---

[-- Attachment #3: jffs2_oops_gc --]
[-- Type: text/plain, Size: 3380 bytes --]

[  223.855712] Unable to handle kernel NULL pointer dereference at virtual address 00000000
[  223.947204] pgd = c0004000
[  223.980438] [00000000] *pgd=00000000
[  223.984039] Internal error: Oops: 17 [#1] PREEMPT
[  223.988769] last sysfs file: /sys/kernel/uevent_seqnum
[  223.993927] Modules linked in: rtc_twl ftdi_sio rtc_core usbserial
[  224.000183] CPU: 0    Not tainted  (2.6.32 #6)
[  224.004669] PC is at crc32_le+0x6c/0xf4
[  224.008514] LR is at jffs2_garbage_collect_live+0xb5c/0xfc8
[  224.014129] pc : [<c0211f28>]    lr : [<c01b14b0>]    psr: 20000113
[  224.014129] sp : ce33bde0  ip : 000000b2  fp : 00000000
[  224.025665] r10: 00000007  r9 : ce596b00  r8 : fffffffc
[  224.030914] r7 : 000000b3  r6 : 00000000  r5 : c03fcf9c  r4 : 00000000
[  224.037445] r3 : 00000000  r2 : 000002cc  r1 : 00000000  r0 : 00000000
[  224.044006] Flags: nzCv  IRQs on  FIQs on  Mode SVC_32  ISA ARM  Segment kernel
[  224.051361] Control: 10c5387d  Table: 8e3c0019  DAC: 00000017
[  224.057128] Process jffs2_gcd_mtd2 (pid: 921, stack limit = 0xce33a2f0)
[  224.063781] Stack: (0xce33bde0 to 0xce33c000)
[  224.068145] bde0: ccff0000 ce33be64 00001000 00000000 00001000 c01b14b0 ce33beac ce33bea8
[  224.076385] be00: ce33a010 c08c554c c05a576c c00d32e0 00000000 00001000 00006888 000081a4
[  224.084594] be20: 00000007 ce3808bc ce1ea200 00000000 ce596b1c 00002000 0001827c ce09de10
[  224.092803] be40: ccff0000 c01b3b04 00000000 00000000 fffffffd 00000000 00002000 00001000
[  224.101013] be60: 00000002 e0021985 00000310 dededdb1 00000023 00000124 000081a4 00000000
[  224.109252] be80: 00006888 4f1d5028 4f1d5038 4f1d5038 00001000 000002cc 00001000 00000007
[  224.117462] bea0: 00000000 b57f0551 000002cc 00001000 c075be00 00000000 0001f9cc 22222222
[  224.125671] bec0: ce1ea22c ce596b00 ce3808bc 00000023 ce1ea200 ce01cb18 0001827c ce09de10
[  224.133880] bee0: ce1ea22c c01b20dc 00000000 00000000 ce1ea2b0 ce1ea290 c006c26c ce3f7b40
[  224.142120] bf00: c0593740 00000000 00000000 00000000 00000000 40000113 ce33a000 00000001
[  224.150329] bf20: ce1ea200 00000000 00000000 00000000 00000000 c01b3678 00000001 00000000
[  224.158538] bf40: 00000080 00000000 00000000 00000000 00000071 0000000f ce3f7b70 c0550c98
[  224.166748] bf60: ce3f7b70 c01b34f4 00000000 c0059ab4 c0550c98 ce3f7b70 ce33bf94 c0059bcc
[  224.174987] bf80: c05507c8 00000000 ce3f7b40 c01b34f4 ce33bfcc c03dc6e4 00000013 ce3f7ddc
[  224.183197] bfa0: ce3f7bb8 ce3f7dd8 c01b34f4 ce33bfd4 cde39e30 ce1ea200 c01b34f4 ce33bfd4
[  224.191406] bfc0: cde39e30 ce1ea200 c01b34f4 c0076cfc 00000000 00000000 ce33bfd8 ce33bfd8
[  224.199645] bfe0: 00000000 00000000 00000000 00000000 00000000 c0039960 00000000 00000000
[  224.207855] [<c0211f28>] (crc32_le+0x6c/0xf4) from [<c01b14b0>] (jffs2_garbage_collect_live+0xb5c/0xfc8)
[  224.217407] [<c01b14b0>] (jffs2_garbage_collect_live+0xb5c/0xfc8) from [<c01b20dc>] (jffs2_garbage_collect_pass+0x7c0/0x8bc)
[  224.228668] [<c01b20dc>] (jffs2_garbage_collect_pass+0x7c0/0x8bc) from [<c01b3678>] (jffs2_garbage_collect_thread+0x184/0x1d8)
[  224.240112] [<c01b3678>] (jffs2_garbage_collect_thread+0x184/0x1d8) from [<c0076cfc>] (kthread+0x7c/0x84)
[  224.249755] [<c0076cfc>] (kthread+0x7c/0x84) from [<c0039960>] (kernel_thread_exit+0x0/0x8)
[  224.258148] Code: e2448004 e3a01000 e1a0c007 ea00000e (e7942001) 
[  226.582031] ---[ end trace 351acc3d8d9196f4 ]---

Re: JFFS2 oops when writing to two partitions simultaneously

[Orjan Friberg]

A couple of new observations in trying to box this in:

Early revisions (A2) of the BeagleBoard xM has both NAND and SD/MMC.  If 
I boot the system (Linux + rootfs) off the SD card (ext3 formatted) and 
create two JFFS2 partitions in the NAND flash, I cannot repeat the 
problem.  That system uses a pretty recent kernel, 3.0.17.

As a sanity check, I ran the 2.6.32 configuration on the xM board to 
verify that it wasn't a problem isolated to our own board.  Sure enough, 
it happens there too.


I'm going to check whether the oops is dependent on Linux + rootfs being 
on a JFFS2 partition or if it's just a matter of kernel version.


On a side note, is there a more easily searchable archive than 
http://lists.infradead.org/pipermail/linux-mtd/?


Thanks,
Orjan

-- 
Orjan Friberg
FlatFrog Laboratories AB

Re: JFFS2 oops when writing to two partitions simultaneously

[Orjan Friberg]

On 01/24/2012 06:15 PM, Orjan Friberg wrote:
> I'm going to check whether the oops is dependent on Linux + rootfs being
> on a JFFS2 partition or if it's just a matter of kernel version.

Slight mistake: the kernel is not in the root filesystem, and does not 
reside in a JFFS2 partition.

Anyway, exposing the bug does not depend solely on whether the root file 
system is one of the JFFS2 partitions being exercised in the test. 
(Only tested in one direction: in a configuration where the bug does not 
show up I moved the rootfs from the SD card to a JFFS2 partition on the 
NAND.)


I'll be trying out various kernel versions next.  Hopefully I'll find 
something isolated that can either be backported or at least convince me 
that this is in fact a JFFS2 bug and support me switching over to UBIFS.

Thanks,
Orjan

-- 
Orjan Friberg
FlatFrog Laboratories AB

Re: JFFS2 oops when writing to two partitions simultaneously

[Orjan Friberg]

On 01/24/2012 08:02 PM, Orjan Friberg wrote:
> I'll be trying out various kernel versions next.

I've boiled it down to whether CONFIG_PREEMPT (bug happens) or 
CONFIG_PREEMPT_VOLUNTARY (bug doesn't happen) is selected.  Of course, 
changing that affects a other things like inline spinlocking.

By changing this option, I've made the bug go away in a 2.6.32 and 
2.6.37 setup where it previously happened, and I've made it appear in a 
2.6.39 setup where it previously didn't happen.


I'll be posting this on linux-omap mailing list too.  I don't have any 
other architecture to try this on, and I'm aware that the problem may 
lie in arch-dependent code (spinlock implementation?).

-- 
Orjan Friberg
FlatFrog Laboratories AB

Re: JFFS2 oops when writing to two partitions simultaneously

[Orjan Friberg]

On 01/25/2012 08:53 PM, Orjan Friberg wrote:
> I've boiled it down to whether CONFIG_PREEMPT (bug happens) or
> CONFIG_PREEMPT_VOLUNTARY (bug doesn't happen) is selected.

No, I haven't.  The problem disappeared only for

   while :; do dd if=/dev/zero of=file bs=800 count=1; done

That one-liner was boiled down from the following program, which still 
oopses instantly:

   #include <stdio.h>
   #include <unistd.h>
   #include <sys/types.h>
   #include <sys/stat.h>
   #include <fcntl.h>

   int main()
   {
     int fd;
     struct stat st;
     char buf[800];

     do {
       unlink("file2");
       fd = open("file1", O_RDWR|O_CREAT|O_TRUNC, 0666);
       stat("file1", &st);
       lseek(fd, 0, SEEK_SET);
       write(fd, buf, 800);
       close(fd);
       rename("file1", "file2");
     } while (1);

     return 0;
   }


(Apologies for spamming.)

-- 
Orjan Friberg
FlatFrog Laboratories AB

Re: JFFS2 oops when writing to two partitions simultaneously

[Joakim Tjernlund]

>
> On 01/25/2012 08:53 PM, Orjan Friberg wrote:
> > I've boiled it down to whether CONFIG_PREEMPT (bug happens) or
> > CONFIG_PREEMPT_VOLUNTARY (bug doesn't happen) is selected.
>
> No, I haven't.  The problem disappeared only for
>
>    while :; do dd if=/dev/zero of=file bs=800 count=1; done
>
> That one-liner was boiled down from the following program, which still
> oopses instantly:
>
>    #include <stdio.h>
>    #include <unistd.h>
>    #include <sys/types.h>
>    #include <sys/stat.h>
>    #include <fcntl.h>
>
>    int main()
>    {
>      int fd;
>      struct stat st;
>      char buf[800];
>
>      do {
>        unlink("file2");
>        fd = open("file1", O_RDWR|O_CREAT|O_TRUNC, 0666);
>        stat("file1", &st);
>        lseek(fd, 0, SEEK_SET);
>        write(fd, buf, 800);
>        close(fd);
>        rename("file1", "file2");
>      } while (1);
>
>      return 0;
>    }

Works for me on PowerPC, 2.6.35, NOR flash

 Jocke

Re: JFFS2 oops when writing to two partitions simultaneously

[Orjan Friberg]

On 01/25/2012 10:01 PM, Orjan Friberg wrote:
> That one-liner was boiled down from the following program, which still
> oopses instantly:

The C program seems to work fine with CONFIG_PREEMPT_NONE=y.

If that is indeed the problem I guess it's reasonable that it worked 
better with PREEMPT_VOLUNTARY than PREEMPT because there are fewer 
preemtion points.

-- 
Orjan Friberg
FlatFrog Laboratories AB

Re: JFFS2 oops when writing to two partitions simultaneously

[Orjan Friberg]

On 01/26/2012 09:19 AM, Joakim Tjernlund wrote:
> Works for me on PowerPC, 2.6.35, NOR flash

Just to clarify: two instances of that program, each on their own partition?

What CONFIG_PREEMPT options are in your kernelconfig?

Thanks.

-- 
Orjan Friberg
FlatFrog Laboratories AB

Re: JFFS2 oops when writing to two partitions simultaneously

[Joakim Tjernlund]

Orjan Friberg <of@flatfrog.com> wrote on 2012/01/26 10:02:20:
>
> On 01/26/2012 09:19 AM, Joakim Tjernlund wrote:
> > Works for me on PowerPC, 2.6.35, NOR flash
>
> Just to clarify: two instances of that program, each on their own partition?

1 to 4 instances on one partition(only got one)

>
> What CONFIG_PREEMPT options are in your kernelconfig?

CONFIG_HZ_1000=y
CONFIG_HZ=1000
CONFIG_SCHED_HRTICK=y
# CONFIG_PREEMPT_NONE is not set
# CONFIG_PREEMPT_VOLUNTARY is not set
CONFIG_PREEMPT=y

Re: JFFS2 oops when writing to two partitions simultaneously

[Joakim Tjernlund]

linux-mtd-bounces@lists.infradead.org wrote on 2012/01/26 10:02:07:

> From: Orjan Friberg <of@flatfrog.com>
> To: <linux-mtd@lists.infradead.org>
> Date: 2012/01/26 10:15
> Subject: Re: JFFS2 oops when writing to two partitions simultaneously
> Sent by: linux-mtd-bounces@lists.infradead.org
>
> On 01/25/2012 10:01 PM, Orjan Friberg wrote:
> > That one-liner was boiled down from the following program, which still
> > oopses instantly:
>
> The C program seems to work fine with CONFIG_PREEMPT_NONE=y.
>
> If that is indeed the problem I guess it's reasonable that it worked
> better with PREEMPT_VOLUNTARY than PREEMPT because there are fewer
> preemtion points.

The spin locking in jffs2_compress() seems broken:

	case JFFS2_COMPR_MODE_SIZE:
	case JFFS2_COMPR_MODE_FAVOURLZO:
		orig_slen = *datalen;
		orig_dlen = *cdatalen;
		spin_lock(&jffs2_compressor_list_lock);
		list_for_each_entry(this, &jffs2_compressor_list, list) {
			/* Skip decompress-only backwards-compatibility and disabled modules */
			if ((!this->compress)||(this->disabled))
				continue;
			/* Allocating memory for output buffer if necessary */
			if ((this->compr_buf_size < orig_slen) && (this->compr_buf)) {
				spin_unlock(&jffs2_compressor_list_lock);

				kfree(this->compr_buf);
				spin_lock(&jffs2_compressor_list_lock);
				this->compr_buf_size=0;
				this->compr_buf=NULL;
			}

....

if 2 threads are competing here, I don't think you can drop the spin lock
temporarily as this routine do.

 Jocke

Re: JFFS2 oops when writing to two partitions simultaneously

[Orjan Friberg]

On 01/26/2012 12:53 PM, Joakim Tjernlund wrote:
> 			/* Allocating memory for output buffer if necessary */
> 			if ((this->compr_buf_size<  orig_slen)&&  (this->compr_buf)) {
> 				spin_unlock(&jffs2_compressor_list_lock);
>
> 				kfree(this->compr_buf);
> 				spin_lock(&jffs2_compressor_list_lock);
> 				this->compr_buf_size=0;
> 				this->compr_buf=NULL;
> 			}
>
> if 2 threads are competing here, I don't think you can drop the spin lock
> temporarily as this routine do.

Agreed.  Both the freeing of this->compr_buf and the usage of it when 
calling the compressor looks weird (because another process holding the 
lock could decide that the buffer is too small and allocate a new one):

    spin_unlock(&jffs2_compressor_list_lock);
    *datalen  = orig_slen;
    *cdatalen = orig_dlen;
    compr_ret = this->compress(data_in, this->compr_buf, datalen, cdatalen);
    spin_lock(&jffs2_compressor_list_lock);


I'm not sure I'm crazy about the allocation either, come to think of it:

if (!this->compr_buf) {
	spin_unlock(&jffs2_compressor_list_lock);
	tmp_buf = kmalloc(orig_slen, GFP_KERNEL);
	spin_lock(&jffs2_compressor_list_lock);
	if (!tmp_buf) {
		printk(KERN_WARNING "JFFS2: No memory for compressor allocation. (%d 
bytes)\n", orig_slen);
		continue;
	}
	else {
		this->compr_buf = tmp_buf;
		this->compr_buf_size = orig_slen;
	}
}

Even though we hold the lock when assigning the new buffer, things could 
have been changed while we're doing the kmalloc.  In this case, maybe 
just dropping the unlock/lock and allocating with GFP_ATOMIC would solve it.

I'm not sure I see why compr_buf has to belong to the compressor.  To 
not have to kmalloc a buffer each and every time?

-- 
Orjan Friberg
FlatFrog Laboratories AB

Re: JFFS2 oops when writing to two partitions simultaneously

[Joakim Tjernlund]

Orjan Friberg <of@flatfrog.com> wrote on 2012/01/26 13:51:30:

> From: Orjan Friberg <of@flatfrog.com>
> To: Joakim Tjernlund <joakim.tjernlund@transmode.se>
> Cc: "linux-mtd@lists.infradead.org" <linux-mtd@lists.infradead.org>
> Date: 2012/01/26 13:51
> Subject: Re: JFFS2 oops when writing to two partitions simultaneously
>
> On 01/26/2012 12:53 PM, Joakim Tjernlund wrote:
> >          /* Allocating memory for output buffer if necessary */
> >          if ((this->compr_buf_size<  orig_slen)&&  (this->compr_buf)) {
> >             spin_unlock(&jffs2_compressor_list_lock);
> >
> >             kfree(this->compr_buf);
> >             spin_lock(&jffs2_compressor_list_lock);
> >             this->compr_buf_size=0;
> >             this->compr_buf=NULL;
> >          }
> >
> > if 2 threads are competing here, I don't think you can drop the spin lock
> > temporarily as this routine do.
>
> Agreed.  Both the freeing of this->compr_buf and the usage of it when
> calling the compressor looks weird (because another process holding the
> lock could decide that the buffer is too small and allocate a new one):

Yes, possibly there is some mutex protecting this?

>
>     spin_unlock(&jffs2_compressor_list_lock);
>     *datalen  = orig_slen;
>     *cdatalen = orig_dlen;
>     compr_ret = this->compress(data_in, this->compr_buf, datalen, cdatalen);
>     spin_lock(&jffs2_compressor_list_lock);
>
>
> I'm not sure I'm crazy about the allocation either, come to think of it:
>
> if (!this->compr_buf) {
>    spin_unlock(&jffs2_compressor_list_lock);
>    tmp_buf = kmalloc(orig_slen, GFP_KERNEL);
>    spin_lock(&jffs2_compressor_list_lock);
>    if (!tmp_buf) {
>       printk(KERN_WARNING "JFFS2: No memory for compressor allocation. (%d
> bytes)\n", orig_slen);
>       continue;
>    }
>    else {
>       this->compr_buf = tmp_buf;
>       this->compr_buf_size = orig_slen;
>    }
> }
>
> Even though we hold the lock when assigning the new buffer, things could
> have been changed while we're doing the kmalloc.  In this case, maybe
> just dropping the unlock/lock and allocating with GFP_ATOMIC would solve it.

The freeing is broken too:
				spin_unlock(&jffs2_compressor_list_lock);
				kfree(this->compr_buf);
				spin_lock(&jffs2_compressor_list_lock);
				this->compr_buf_size=0;
				this->compr_buf=NULL;

First kfree then assign NULL,0? Thats broken either way

Anyhow, I think it is stupid (and probably buggy) to have kfree and kmalloc
as separate. Why is it not done at the same time?

>
> I'm not sure I see why compr_buf has to belong to the compressor.  To
> not have to kmalloc a buffer each and every time?

Probably

Re: JFFS2 oops when writing to two partitions simultaneously

[Orjan Friberg]

On 01/26/2012 02:16 PM, Joakim Tjernlund wrote:
> Anyhow, I think it is stupid (and probably buggy) to have kfree and kmalloc
> as separate. Why is it not done at the same time?

To me it looks like the lock must be held the entire time.  We can't 
allow two contexts using (i.e. freeing/allocating/writing to) the 
compressor's compr_buf.

Maybe the lock used here should be on a per-compressor basis, rather 
than on the list as a whole.  (The list lock is still needed when adding 
to/removing from the list of course.)

-- 
Orjan Friberg
FlatFrog Laboratories AB

Re: JFFS2 oops when writing to two partitions simultaneously

[Joakim Tjernlund]

Orjan Friberg <of@flatfrog.com> wrote on 2012/01/26 15:07:07:
>
> On 01/26/2012 02:16 PM, Joakim Tjernlund wrote:
> > Anyhow, I think it is stupid (and probably buggy) to have kfree and kmalloc
> > as separate. Why is it not done at the same time?
>
> To me it looks like the lock must be held the entire time.  We can't
> allow two contexts using (i.e. freeing/allocating/writing to) the
> compressor's compr_buf.

This is more complex than I got time for. I can say there is more to it though.
Compare
	case JFFS2_COMPR_MODE_PRIORITY:
		output_buf = kmalloc(*cdatalen,GFP_KERNEL);

and

case JFFS2_COMPR_MODE_SIZE:
	case JFFS2_COMPR_MODE_FAVOURLZO:
		orig_slen = *datalen;
		orig_dlen = *cdatalen;
..
tmp_buf = kmalloc(orig_slen, GFP_KERNEL);

It is not the same len used to kmalloc!

I would stay away from JFFS2_COMPR_MODE_SIZE and JFFS2_COMPR_MODE_FAVOURLZO
all together as it looks broken in more than one way.

>
> Maybe the lock used here should be on a per-compressor basis, rather
> than on the list as a whole.  (The list lock is still needed when adding
> to/removing from the list of course.)
>
> --
> Orjan Friberg
> FlatFrog Laboratories AB

Re: JFFS2 oops when writing to two partitions simultaneously

[Joakim Tjernlund]

Orjan Friberg <of@flatfrog.com> wrote on 2012/01/26 15:07:07:
>
> On 01/26/2012 02:16 PM, Joakim Tjernlund wrote:
> > Anyhow, I think it is stupid (and probably buggy) to have kfree and kmalloc
> > as separate. Why is it not done at the same time?
>
> To me it looks like the lock must be held the entire time.  We can't
> allow two contexts using (i.e. freeing/allocating/writing to) the
> compressor's compr_buf.
>
> Maybe the lock used here should be on a per-compressor basis, rather
> than on the list as a whole.  (The list lock is still needed when adding
> to/removing from the list of course.)

Did look some more and to me it seems like the whole kmalloc/kfree dance is pointless.
The end result is the same as for JFFS2_COMPR_MODE_PRIORITY w.r.t buffer mgmt as the
compressor doesn't own the buffer anyway. It gets freed by jffs2_free_comprbuf()
after it has been written to flash.

Maybe I am missing something?

 Jocke

Re: JFFS2 oops when writing to two partitions simultaneously

[Orjan Friberg]

On 01/26/2012 03:23 PM, Joakim Tjernlund wrote:
> I would stay away from JFFS2_COMPR_MODE_SIZE and JFFS2_COMPR_MODE_FAVOURLZO
> all together as it looks broken in more than one way.

CMODE_PRIORITY seems to work fine for me so I'll probably go with that. 
  Still, it would be nice if this was fixed or at least marked as broken 
(or removed if no-one is using it).  I don't think I can do the rewrite, 
but I'd be happy to try patches if someone else decides it's worth fixing.

Thanks for your help Joakim.

-- 
Orjan Friberg
FlatFrog Laboratories AB

Re: JFFS2 oops when writing to two partitions simultaneously

[Joakim Tjernlund]

>
> Orjan Friberg <of@flatfrog.com> wrote on 2012/01/26 15:07:07:
> >
> > On 01/26/2012 02:16 PM, Joakim Tjernlund wrote:
> > > Anyhow, I think it is stupid (and probably buggy) to have kfree and kmalloc
> > > as separate. Why is it not done at the same time?
> >
> > To me it looks like the lock must be held the entire time.  We can't
> > allow two contexts using (i.e. freeing/allocating/writing to) the
> > compressor's compr_buf.
> >
> > Maybe the lock used here should be on a per-compressor basis, rather
> > than on the list as a whole.  (The list lock is still needed when adding
> > to/removing from the list of course.)
>
> Did look some more and to me it seems like the whole kmalloc/kfree dance is pointless.
> The end result is the same as for JFFS2_COMPR_MODE_PRIORITY w.r.t buffer mgmt as the
> compressor doesn't own the buffer anyway. It gets freed by jffs2_free_comprbuf()
> after it has been written to flash.
>
> Maybe I am missing something?

Yes, I did. This dance is there to save you an extra kmalloc in most cases.

Maybe you can get away with removing the extra lock dropping around kfree/kmalloc
and if you do, you can simply the code to something like:

			if ((this->compr_buf_size < orig_slen) || !this->compr_buf) {
				tmp_buf = kmalloc(orig_slen, GFP_ATOMIC);
				if (!tmp_buf) {
					printk(KERN_WARNING "JFFS2: No memory for compressor allocation. (%d bytes)\n", orig_slen);
					continue;
				}
				kfree(this->compr_buf);
				this->compr_buf = tmp_buf;
				this->compr_buf_size = orig_slen;
			}

Then have a good look at whether to use orig_slen or orig_dlen

 Jocke

Re: JFFS2 oops when writing to two partitions simultaneously

[Joakim Tjernlund]

Orjan Friberg <of@flatfrog.com> wrote on 2012/01/26 15:53:54:
>
> On 01/26/2012 03:23 PM, Joakim Tjernlund wrote:
> > I would stay away from JFFS2_COMPR_MODE_SIZE and JFFS2_COMPR_MODE_FAVOURLZO
> > all together as it looks broken in more than one way.
>
> CMODE_PRIORITY seems to work fine for me so I'll probably go with that.
>   Still, it would be nice if this was fixed or at least marked as broken
> (or removed if no-one is using it).  I don't think I can do the rewrite,
> but I'd be happy to try patches if someone else decides it's worth fixing.

You could try removing the lock dropping, one at a time, to see if it makes a difference.
That would be a data point for anyone wanting to fix this.

>
> Thanks for your help Joakim.

NP
      Jocke

Re: JFFS2 oops when writing to two partitions simultaneously

[Orjan Friberg]

On 01/26/2012 04:09 PM, Joakim Tjernlund wrote:
> Maybe you can get away with removing the extra lock dropping around kfree/kmalloc
> and if you do, you can simply the code to something like:

But you'd still need to hold the lock over

   this->compress(data_in, this->compr_buf, datalen, cdatalen);

right?

-- 
Orjan Friberg
FlatFrog Laboratories AB

Re: JFFS2 oops when writing to two partitions simultaneously

[Orjan Friberg]

On 01/26/2012 04:17 PM, Joakim Tjernlund wrote:
> You could try removing the lock dropping, one at a time, to see if it makes a difference.
> That would be a data point for anyone wanting to fix this.

I'll turn on CONFIG_DEBUG_SPINLOCK and CONFIG_DEBUG_SPINLOCK_SLEEP and 
see what happens.


-- 
Orjan Friberg
FlatFrog Laboratories AB

Re: JFFS2 oops when writing to two partitions simultaneously

[Orjan Friberg]

On 01/26/2012 04:25 PM, Orjan Friberg wrote:
> On 01/26/2012 04:17 PM, Joakim Tjernlund wrote:
>> You could try removing the lock dropping, one at a time, to see if it makes a difference.
>> That would be a data point for anyone wanting to fix this.
>
> I'll turn on CONFIG_DEBUG_SPINLOCK and CONFIG_DEBUG_SPINLOCK_SLEEP and
> see what happens.

As expected, dropping the lock around kmalloc was fine once I changed 
GFP_KERNEL to GFP_ATOMIC.

Dropping the lock around kfree worked fine (I didn't think it would).

And, as you suggested, we could probably combine those.


We must hold the lock when calling this->compress (to protect compr_buf; 
we oops without it) but in doing so I get

BUG: sleeping function called from invalid context at kernel/mutex.c:85

because jffs2_lzo_compress does a mutex_lock.


Even if it did work, I think we'd unneccessarily be limiting the 
throughput in that piece of code by holding the lock for that long.

-- 
Orjan Friberg
FlatFrog Laboratories AB

Re: JFFS2 oops when writing to two partitions simultaneously

[Joakim Tjernlund]

Orjan Friberg <of@flatfrog.com> wrote on 2012/01/26 17:05:15:
>
> On 01/26/2012 04:25 PM, Orjan Friberg wrote:
> > On 01/26/2012 04:17 PM, Joakim Tjernlund wrote:
> >> You could try removing the lock dropping, one at a time, to see if it makes a difference.
> >> That would be a data point for anyone wanting to fix this.
> >
> > I'll turn on CONFIG_DEBUG_SPINLOCK and CONFIG_DEBUG_SPINLOCK_SLEEP and
> > see what happens.
>
> As expected, dropping the lock around kmalloc was fine once I changed
> GFP_KERNEL to GFP_ATOMIC.
>
> Dropping the lock around kfree worked fine (I didn't think it would).
>
> And, as you suggested, we could probably combine those.
>
>
> We must hold the lock when calling this->compress (to protect compr_buf;
> we oops without it) but in doing so I get
>
> BUG: sleeping function called from invalid context at kernel/mutex.c:85
>
> because jffs2_lzo_compress does a mutex_lock.
>
>
> Even if it did work, I think we'd unneccessarily be limiting the
> throughput in that piece of code by holding the lock for that long.

Agreed on all points above :)

Its pretty hopeless to fix too. The only way I can see is to kmalloc
bufs as you need(will be 2 kmalloc's). This would simplify the
code too. I am not going to work on that though as I don't use it and
and don't even like the idea behind it.

 Jocke