espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
12.57k stars 7.02k forks source link

Panic in I2C driver when reading from I2C EEPROM chip (IDFGH-12697) #13687

Open sfzhi opened 3 weeks ago

sfzhi commented 3 weeks ago

Answers checklist.

IDF version.

5.2.1

Espressif SoC revision.

ESP32-C3 revision 0.4

Operating System used.

Linux

How did you build your project?

Command line with idf.py

If you are using Windows, please specify command line type.

None

Development Kit.

Seeed XIAO ESP32C3

Power Supply used.

USB

What is the expected behavior?

It should be possible to read a longer sequence of bytes from an external EEPROM over I2C.

What is the actual behavior?

Guru Meditation Error: Core  0 panic'ed (Store access fault). Exception was unhandled.

Core  0 register dump:
MEPC    : 0x40382350  RA      : 0x40382332  SP      : 0x3fc97970  GP      : 0x3fc94a00
TP      : 0x3fc7b4a4  T0      : 0x0000001f  T1      : 0x600c2140  T2      : 0x00000002
S0/FP   : 0x3fcae2c4  S1      : 0x3fcae2e8  A0      : 0x3fcae2c4  A1      : 0x00000020
A2      : 0x60013000  A3      : 0x00000020  A4      : 0x00000053  A5      : 0x00000001
A6      : 0xa0000000  A7      : 0x0000000a  S2      : 0x3fcae1ac  S3      : 0x3fcae1ac
S4      : 0xffffffff  S5      : 0x00000001  S6      : 0x3fc9e858  S7      : 0x3fca0ce4
S8      : 0x00000075  S9      : 0x00000001  S10     : 0x0000005a  S11     : 0x00000010
T3      : 0x00000038  T4      : 0x3fca11cc  T5      : 0x00001800  T6      : 0x00000000
MSTATUS : 0x00001881  MTVEC   : 0x40380001  MCAUSE  : 0x00000007  MTVAL   : 0x00000000
MHARTID : 0x00000000

Stack memory:
3fc97970: 0x00000000 0x3fcae1c4 0x00000053 0x40383fbc 0x000000ff 0x3fcae1c4 0x3fc9aaf8 0x40383f7a
3fc97990: 0x00000000 0x80000007 0x60023000 0x00000001 0x00001881 0x8000000b 0x3fcae590 0x40380f5a
3fc979b0: 0x00001881 0x80000007 0x00000009 0x403801e8 0x60023000 0x4038665c 0x40386668 0x00000000
3fc979d0: 0x3fc979cc 0x00000000 0x00000000 0x00000000 0x3fc979e4 0xffffffff 0x3fc979e4 0x3fc979e4
3fc979f0: 0x00000000 0x3fc979f8 0xffffffff 0x3fc979f8 0x3fc979f8 0x00000001 0x00000001 0x00000000
3fc97a10: 0x0001ffff 0x00000000 0x00000000 0x00000000 0x00000000 0x3fc97a20 0x00000000 0x00000000
3fc97a30: 0x00000000 0x3fc97a38 0xffffffff 0x3fc97a38 0x3fc97a38 0x00000000 0x3fc97a4c 0xffffffff
3fc97a50: 0x3fc97a4c 0x3fc97a4c 0x00000001 0x00000001 0x00000000 0x0001ffff 0x00000000 0x00000000
3fc97a70: 0x00000000 0x3fc9e60c 0x3fc9e674 0x3fca1ed8 0x3fca32f8 0x00000000 0x00000000 0x00000000
3fc97a90: 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000

Steps to reproduce.

  1. 24LC04 EEPROM chip is connected to the I2C bus.
  2. i2c_new_master_bus(...) - as usually
  3. i2c_master_bus_add_device(...) - as usually
  4. Try to read a sequence of bytes starting from the given address:
    uint8_t addr = 0;
    uint8_t data[256];
    size_t size = 73; // any number between 32 and 256
    i2c_master_transmit_receive(device, &addr, sizeof(addr), data, size, 10);

    From my observations, for the problem to occur, these two conditions must be true at the same time:

    • The length of the data to be read is >= 32 (the problem does not occur if the length to be read is < 32).
    • The device must have been reset using the reset button (which is an equivalent of power-on reset, if I'm not mistaken). The problem does not occur after other kinds of reset, such as via USB or by calling esp_restart().

If both conditions are true, the problem is 100% reproducible.

Debug Logs.

$ riscv32-esp-elf-addr2line -pfiaC -e build/whatever.elf 0x40382350
0x40382350: i2c_ll_read_rxfifo at /COMPONENT_HAL_DIR/esp32c3/include/hal/i2c_ll.h:613
 (inlined by) i2c_isr_receive_handler at /COMPONENT_DRIVER_DIR/i2c/i2c_master.c:533
 (inlined by) i2c_master_isr_handler_default at /COMPONENT_DRIVER_DIR/i2c/i2c_master.c:586

More Information.

The relevant part of the code disassembled by GDB:

/COMPONENT_DRIVER_DIR/i2c/i2c_master.c:                                                                                                                                                         
530         if (i2c_master->status == I2C_STATUS_READ) {                                                                                                                                        
   0x40382318 <+396>:   fence                                                                                                                                                                   
   0x4038231c <+400>:   lw      a5,12(s0)                                                                                                                                                       
   0x4038231e <+402>:   fence                                                                                                                                                                   
   0x40382322 <+406>:   bnez    a5,0x403823a6 <i2c_master_isr_handler_default+538>                                                                                                              

531             i2c_operation_t *i2c_operation = &i2c_master->i2c_trans.ops[i2c_master->trans_idx];                                                                                             
   0x40382324 <+408>:   lhu     a5,132(s0)                                                                                                                                                      
   0x40382328 <+412>:   lw      s1,28(s0)                                                                                                                                                       
   0x4038232a <+414>:   slli    a5,a5,0x4                                                                                                                                                       
   0x4038232c <+416>:   add     s1,s1,a5                                                                                                                                                        

532             portENTER_CRITICAL_ISR(&i2c_master->base->spinlock);                                                                                                                            
   0x4038232e <+418>:   jal     ra,0x40388b6c <vPortEnterCritical>                                                                                                                              

533             i2c_ll_read_rxfifo(hal->dev, i2c_operation->data + i2c_operation->bytes_used, i2c_master->rx_cnt);                                                                              
   0x40382332 <+422>:   lw      a1,20(s0)                                                                                                                                                       
   0x40382334 <+424>:   lw      a2,12(s3)                                                                                                                                                       
   0x40382338 <+428>:   lw      a5,4(s1)                                                                                                                                                        
   0x4038233a <+430>:   zext.b  a3,a1                                                                                                                                                           
   0x4038233e <+434>:   lhu     a4,8(s1)                                                                                                                                                        

/COMPONENT_HAL_DIR/esp32c3/include/hal/i2c_ll.h:                                                                                                                                                
612         for (int i = 0; i < len; i++) {                                                                                                                                                     
   0x40382342 <+438>:   beqz    a3,0x4038235e <i2c_master_isr_handler_default+466>                                                                                                              
   0x40382344 <+440>:   add     a5,a5,a4                                                                                                                                                        
   0x40382346 <+442>:   add     a3,a3,a5                                                                                                                                                        

613             ptr[i] = HAL_FORCE_READ_U32_REG_FIELD(hw->fifo_data, data);                                                                                                                     
   0x40382348 <+444>:   lw      a4,28(a2)                                                                                                                                                       
   0x4038234a <+446>:   addi    a5,a5,1                                                                                                                                                         
   0x4038234c <+448>:   sw      a4,8(sp)                                                                                                                                                        
   0x4038234e <+450>:   lw      a4,8(sp)                                                                                                                                                        
   0x40382350 <+452>:   sb      a4,-1(a5)                                                                                                                                                       

612         for (int i = 0; i < len; i++) {                                                                                                                                                     
   0x40382354 <+456>:   bne     a3,a5,0x40382348 <i2c_master_isr_handler_default+444>                                                                                                           

/COMPONENT_DRIVER_DIR/i2c/i2c_master.c:                                                                                                                                                         
535             i2c_master->w_r_size = i2c_master->rx_cnt;                                                                                                                                      
   0x40382358 <+460>:   lw      a1,20(s0)                                                                                                                                                       

536             i2c_operation->bytes_used += i2c_master->rx_cnt;                                                                                                                                
   0x4038235a <+462>:   lhu     a4,8(s1)                                                                                                                                                        

535             i2c_master->w_r_size = i2c_master->rx_cnt;                                                                                                                                      
   0x4038235e <+466>:   add     a4,a4,a1                                                                                                                                                        
   0x40382360 <+468>:   slli    a4,a4,0x10                                                                                                                                                      

As can be seen from the register dump above, the exact spot where the problem occurs is 0x40382350 <+452>: sb a4,-1(a5), which is the assignment to ptr[i] inside i2c_ll_read_rxfifo(...). Apparently the destination address (stored in a5 and already incremented for the next loop iteration) is NULL.

mythbuster5 commented 2 weeks ago

@sfzhi I tried to reproduce with our i2c_eeprom_main example but failed. Could you please provide your sdkconfig?

mythbuster5 commented 2 weeks ago

IIRC,power-on reset will reset all condition, so after power-on reset, everything should begin as start. Some panic happen after power-on reset looks very strange to me even if GDB shows something. So 1. I want to see your configuration 2. See your reset reason

ESP-ROM:esp32c3-api1-20210207
Build:Feb  7 2021
rst:0x1 (POWERON),boot:0xc (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
sfzhi commented 2 weeks ago

Here you go:

ESP-ROM:esp32c3-api1-20210207                                                    
Build:Feb  7 2021                                                                
rst:0x1 (POWERON),boot:0xe (SPI_FAST_FLASH_BOOT)                                 
SPIWP:0xee                                                                       
mode:DIO, clock div:1                                                            
load:0x3fcd5820,len:0x1880                                                       
load:0x403cc710,len:0xd50                                                        
load:0x403ce710,len:0x2f50                                                       
entry 0x403cc71a                                                                 

The sdkconfig file: sdkconfig.txt.

sfzhi commented 2 weeks ago

I have conducted a few more experiments and the results are even more puzzling than before. When the panic occurs, if I don't wait until the device is restarted automatically (after 3 seconds, as per the configuration), but press the reset button again immediately, the device boots fine and the problem does not occur. I can't think of any reasonable explanation of what's happening.

sfzhi commented 1 week ago

Even more experiments resulted in the following observations and conclusions: