2008-04-29 16:34:41     open/fopen sometimes fails on jffs2

2008-04-29 16:34:41     open/fopen sometimes fails on jffs2

Cameron Barfield (UNITED STATES)

Message: 55244    Howdy.

I'm running 2008RC1. I have a secondary (not used for booting) m125p128 serial (SPI) flash formatted as JFFS2 and mounted. I'm currently using this device to store configuration information for some applications.

Sometimes calls to fopen (I've also tried with open) go to lunch when I try to open a file on the serial flash. I've run my app through GDB server, but when single stepping through the open call, it seems to work. I did manage to get a kernel dump:

    Write of 122 bytes at 0x00f80174 failed. returned 1, retlen 0

    Not marking the space at 0x00f80174 as dirty because the flash driver returned retlen zero

    NULL pointer access (probably)

    Kernel OOPS in progress

    Defered Exception context

    CURRENT PROCESS:

    COMM=cyberlcd PID=208

    TEXT = 0x00810000-0x00818c18        DATA = 0x00358c18-0x0035afd0

     BSS = 0x0035afd0-0x00840000  USER-STACK = 0x0085fed0

    return address: [0x0006c03c]; contents of:

    0x0006c010:  3208  e142  0012  e140  0014  e102  1124  e100

    0x0006c020:  e640  914a  e411  0029  e3fd  0b2e  2fea  0000

    0x0006c030:  05f3  e800  0003  323a  3218  3039 [a0ba] 0c02

    0x0006c040:  1884  0000  0000  a079  3047  e3ff  ffcd  3220

    SEQUENCER STATUS:               Not tainted

     SEQSTAT: 00000027  IPEND: 8030  SYSCFG: 0006

      HWERRCAUSE: 0x0

      EXCAUSE   : 0x27

      physical IVG15 asserted : <0xffa00e60> { _evt_system_call + 0x0 }

      logical irq   6 mapped  : <0xffa00250> { _timer_interrupt + 0x0 }

      logical irq  12 mapped  : <0x000c8c14> { _rx_handler + 0x0 }

      logical irq  13 mapped  : <0x000c8c70> { _tx_handler + 0x0 }

      logical irq  17 mapped  : <0x000b5158> { _dma_irq_handler + 0x0 }

      logical irq  18 mapped  : <0x0009ecf4> { _bfin_serial_rx_int + 0x0 }

      logical irq  19 mapped  : <0x0009ee94> { _bfin_serial_tx_int + 0x0 }

      logical irq  24 mapped  : <0x000a83d4> { _bf537mac_interrupt + 0x0 }

      logical irq  45 mapped  : <0x000c9760> { _err_handler + 0x0 }

     RETE: <0x00000000> /* Maybe null pointer? */

     RETN: <0x0035dbf8> /* unknown address */

     RETX: <0x0006c03c> { _jffs2_add_full_dnode_to_inode + 0xc }

     RETS: <0x0006ff42> { _jffs2_write_inode_range + 0x22a }

     PC  : <0x0006c03c> { _jffs2_add_full_dnode_to_inode + 0xc }

    DCPLB_FAULT_ADDR: <0x00000008> /* Maybe null pointer? */

    ICPLB_FAULT_ADDR: <0x0006c03c> { _jffs2_add_full_dnode_to_inode + 0xc }

    PROCESSOR STATE:

     R0 : 0338d200    R1 : 037c8d1c    R2 : 00000001    R3 : 0000001f

     R4 : 00000128    R5 : 00000000    R6 : 00000001    R7 : 037c8d1c

     P0 : 006a6540    P1 : 00000001    P2 : 00172578    P3 : 0338d200

     P4 : 037c8d1c    P5 : 008834f8    FP : 00000001    SP : 0035db1c

     LB0: ffa01d64    LT0: ffa01d62    LC0: 00000000

     LB1: 0008c8ea    LT1: 0008c8dc    LC1: 00000000

     B0 : 00000000    L0 : 00000000    M0 : 00000000    I0 : 006758ec

     B1 : 00000000    L1 : 00000000    M1 : 00000000    I1 : 00000000

     B2 : 00000000    L2 : 00000000    M2 : 00000000    I2 : 0002fa06

     B3 : 00000000    L3 : 00000000    M3 : 00000000    I3 : 00000000

    A0.w: 000000a0   A0.x: 00000000   A1.w: 000000a0   A1.x: 00000000

    USP : 0085fd38  ASTAT: 02002022

    Hardware Trace:

       0 Target : <0x0000483c> { _trap_c + 0x0 }

         Source : <0xffa0076c> { _exception_to_level5 + 0xb4 }

       1 Target : <0xffa006b8> { _exception_to_level5 + 0x0 }

         Source : <0xffa00614> { _ex_trap_c + 0x5c }

       2 Target : <0xffa005b8> { _ex_trap_c + 0x0 }

         Source : <0xffa00442> { _ex_workaround_261 + 0x22 }

       3 Target : <0xffa00420> { _ex_workaround_261 + 0x0 }

         Source : <0xffa0080c> { _trap + 0x28 }

       4 Target : <0xffa007e4> { _trap + 0x0 }

         Source : <0xffa0055a> { _bfin_return_from_exception + 0xe }

       5 Target : <0xffa0054c> { _bfin_return_from_exception + 0x0 }

         Source : <0xffa00432> { _ex_workaround_261 + 0x12 }

       6 Target : <0xffa00420> { _ex_workaround_261 + 0x0 }

         Source : <0xffa0080c> { _trap + 0x28 }

       7 Target : <0xffa007e4> { _trap + 0x0 }

         Source : <0x0006c03a> { _jffs2_add_full_dnode_to_inode + 0xa }

       8 Target : <0x0006c030> { _jffs2_add_full_dnode_to_inode + 0x0 }

         Source : <0x0006ff3e> { _jffs2_write_inode_range + 0x226 }

       9 Target : <0x0006ff2e> { _jffs2_write_inode_range + 0x216 }

         Source : <0x0003460e> { _kfree + 0x6e }

      10 Target : <0x000345a0> { _kfree + 0x0 }

         Source : <0x0006980c> { _jffs2_free_comprbuf + 0x4 }

      11 Target : <0x00069808> { _jffs2_free_comprbuf + 0x0 }

         Source : <0x0006ff2a> { _jffs2_write_inode_range + 0x212 }

      12 Target : <0x0006ff20> { _jffs2_write_inode_range + 0x208 }

         Source : <0x0006faea> { _jffs2_write_dnode + 0x26a }

      13 Target : <0x0006fade> { _jffs2_write_dnode + 0x25e }

         Source : <0x0006fa52> { _jffs2_write_dnode + 0x1d2 }

      14 Target : <0x0006fa50> { _jffs2_write_dnode + 0x1d0 }

         Source : <0x000346d6> { _kmem_cache_free + 0x7a }

      15 Target : <0x0003465c> { _kmem_cache_free + 0x0 }

         Source : <0x0006c520> { _jffs2_free_full_dnode + 0x10 }

    Stack from 0035dafc:

            0000005e ffa00770 0017256c 0017256c 00172568 0000001f 00000001 0000ffff

            0006c03c 00008030 00000027 00000000 0035dbf8 0006c03c 0006c03c 0006ff42

            0338d200 02002022 0008c8ea ffa01d64 0008c8dc ffa01d62 00000000 00000000

            000000a0 00000000 000000a0 00000000 00000000 00000000 00000000 00000000

            00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000

            00000000 0002fa06 00000000 006758ec 0085fd38 00000001 008834f8 037c8d1c

    Call Trace:

    [<0006ff20>] _jffs2_write_inode_range+0x208/0x390

    [<0006ff42>] _jffs2_write_inode_range+0x22a/0x390

    [<00028900>] _request_irq+0x90/0x94

    [<0003fe8c>] _sys_mkdirat+0x38/0xb8

    [<0006b394>] _jffs2_commit_write+0x12c/0x264

    [<0002b1c4>] _generic_file_buffered_write+0x150/0x520

    [<0003d640>] _do_lookup+0x14/0x114

    [<0003e97c>] ___link_path_walk+0xd0/0xc38

    [<0009c252>] _uart_start+0x1e/0x28

    [<000113d0>] _current_fs_time+0x38/0x40

    [<0004f8f6>] ___mark_inode_dirty+0x22/0x14c

    [<0002b776>] ___generic_file_aio_write_nolock+0x1e2/0x3a0

    [<0002b988>] _generic_file_aio_write+0x54/0xe4

    [<0003e42a>] _may_open+0x42/0x17c

    [<0003759c>] _do_sync_write+0xac/0xe4

    [<0009eb9c>] _bfin_serial_tx_chars+0xc4/0xcc

    [<0009eb9c>] _bfin_serial_tx_chars+0xc4/0xcc

    [<0009c240>] _uart_start+0xc/0x28

    [<0001d3c0>] _autoremove_wake_function+0x0/0x30

    [<0009552c>] _tty_write+0x78/0x174

    [<0009456c>] _tty_wakeup+0x24/0x50

    [<00037d42>] _vfs_write+0xc6/0xf4

    [<00037cfe>] _vfs_write+0x82/0xf4

    [<00038172>] _sys_write+0x32/0x64

    [<00038140>] _sys_write+0x0/0x64

    [<00008000>] _l1sram_alloc+0x20/0x34

    [<00003333>] _do_signal+0x6e3/0xd74

    [<00003333>] _do_signal+0x6e3/0xd74

Here's the code:

    int WriteNVSettings(struct nvlcdsettings_t *nv)

    {

    //     FILE* fp;

        int fd;

        int result = 1;

        printf("Opening %s\n", nv->nvlcdpath);

        fd = open( nv->nvlcdpath, (O_SYNC | O_CREAT | O_RDWR) );

        if(fd == -1)

        {

            printf("error opening nvlcd file for writing\n");

            return 0;

        }

        printf( "Attempting to write %d bytes to flash\n", sizeof(struct nvlcdsettings_t) );

        result = write( fd, (void *)nv, sizeof(struct nvlcdsettings_t) );

        printf( "wrote %d of %d bytes to flash\n", result, sizeof(struct nvlcdsettings_t) );

        close(fd);

    /*

        fp = fopen(nv->nvlcdpath, "wb");

        if (fp == NULL)

        {

            printf("error opening nvlcd file for writing!\n");

            return 0;

        }

    //    printf("nvlcd: opened the nvlcdpath\n");

        result = fwrite((void*)nv, 1, sizeof(struct nvlcdsettings_t), fp);

      

    //    printf("nvlcd: wrote to the flash\n");

        fclose(fp);

    */  

    //    printf("nvlcd: closed the flash\n");

        printf("nvlcd: finished writing to the flash\n");

        return result;

    }

Any ideas?

QuoteReplyEditDelete

2008-04-29 23:40:54     Re: open/fopen sometimes fails on jffs2

Frank Van Hooft (CANADA)

Message: 55261    If this is an intermittent problem, have you tried running it with a slower SPI clock? Maybe you're getting noise / reflections or something on the clock / data lines. Running at a slower SPI clock might produce an interesting data point.

Also, have you tried reading back the data you've been writing? Like, doing the equivilent of a memory test for an hour? This would be a good detect for any potential hardware problems. Be nice to rule out hardware problems before digging through a pile of s/w.

My 1 cent worth.  (Don't think it's worth 2 :-)

QuoteReplyEditDelete

2008-04-30 00:45:56     Re: open/fopen sometimes fails on jffs2

Robin Getz (UNITED STATES)

Message: 55268    Cameron:

Frank is correct - I have some some manufactures of SPI flashes have different levels of robustness when it comes to reflections, and noise on the clock lines. (No glitch protection == they sometimes see them as extra clocks, and the SPI gets confused). I might try a scope probe on things, and see if that makes the problem go away (and if so, add 30pf to the SPI CLK line).

-Robin

QuoteReplyEditDelete

2008-04-30 11:51:29     Re: open/fopen sometimes fails on jffs2

Cameron Barfield (UNITED STATES)

Message: 55301    I'd planned on hooking up a scope this morning. We'd had some other issues before (turned out to be the WP and HOLD lines were floating instead of being tied to 3.3V as per the reference design), but all the signals did look good.

I figured I'd ask since this is essentially the same serial flash on the STAMP; it just has a larger capacity.

Thanks.