Skip to content

[ESP32] I2C Interrupt problem since uprade to Espressif 1.1.0 #1588

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
cyberman54 opened this issue Jul 4, 2018 · 102 comments
Closed

[ESP32] I2C Interrupt problem since uprade to Espressif 1.1.0 #1588

cyberman54 opened this issue Jul 4, 2018 · 102 comments

Comments

@cyberman54
Copy link
Contributor

cyberman54 commented Jul 4, 2018

I'm using u8x8 on ESP32 boards, programmed with Arduino Espressif32 core.
I2C display handling using driver U8X8_SSD1306_128X64_NONAME_HW_I2C

This worked perfectly until last days the Espressif32 core was updated from v1.0.2 to v1.1.0.

Since then i get this error during runtime:
[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0

And the display write speed is significantly reduced.

I'm not sure if this is a problem with u8x8 or the Espressif32 core. I'm not using any other I2C communication on the board.

Cross reference to u8x8:
olikraus/u8g2#646 (comment)

@cyberman54
Copy link
Contributor Author

Wrong assignment, re-opened this issue at
platformio/platform-espressif32#107

@cyberman54
Copy link
Contributor Author

Platformio owner pointed me back to here, so i reopen this issue here.

@cyberman54 cyberman54 reopened this Jul 4, 2018
@stickbreaker
Copy link
Contributor

stickbreaker commented Jul 4, 2018

@cyberman54 I just answered your issue on the platformio repo 107
updating to the newest core will solve most of that error message. The 'injection' error has only been caused by overlapping multi-task use of Wire() review your code to verify that all access to Wire() are single-threaded.

Chuck.

@cyberman54
Copy link
Contributor Author

cyberman54 commented Jul 8, 2018

@stickbreaker Problem with the confusing debug messages is now solved, thanks to your pull request.
But it still have the problem with the interrupt injections with Espressif32 core 1.1.x, while the same code on the same device runs with Espressif32 core 1.0.2 without this problem.

@stickbreaker
Copy link
Contributor

@cyberman54 the injection error is showing that the ISR was call, but the control structure was not configured for operation, there is a stage variable that has three possible values, STARTUP, RUNNING, and DONE. as you can see by the debug message, it's value was DONE. so the ISR should not have be triggered. Stage is set to done in three places of my code.

  • first During ISR init(i2cProcQueue)
  • second when the i2c transaction queue has completed (i2cExit)
  • Third If the i2c transaction exceed the configured Timeout, (i2cProcQueue)
    Either a Bus Busy error
    Or a Gross Timeout error

Of these three sections of code, the first one was the source I traced down when Wire() was call by multiple tasks in a 'Ardunio' as Component under IDF, the MUTEX was disabled when Arduino is used as a component.

I cannot imagine how the second could result in an injection event. (it happens during interrupt context)

The Third could only happen if the timeout expired, the foreground task started cleaning up the timeout, but before it output the log messages of the failure (Gross timeout, Bus Busy) an i2c interrupt triggered. I cannot see this happening: here is the code. The interrupt would have to trigger before int_ena.val=0 but after stage=I2C_DONE. Well, It couldn't because it would have had to trigger after the int_ena.val=0 for 0x00 to be shown in the debug message. But int_ena controls the hardware interrupt generation. If it is cleared, no hardware interrupt can be generated by the i2c peripheral.
I'm confused. Something else is happening. My best guess is multi-tasking of Wire()

    } else { // GROSS timeout, shutdown ISR , report Timeout
        i2c->stage = I2C_DONE;
        i2c->dev->int_ena.val =0;
        i2c->dev->int_clr.val = 0x1FFF;
        if((i2c->queuePos==0)&&(i2c->byteCnt==0)) { // Bus Busy no bytes Moved
            reason = I2C_ERROR_BUSY;
            eBits = eBits | EVENT_ERROR_BUS_BUSY|EVENT_ERROR|EVENT_DONE;
#if ARDUHAL_LOG_LEVEL >= ARDUHAL_LOG_LEVEL_ERROR
            log_e(" Busy Timeout start=0x%x, end=0x%x, =%d, max=%d error=%d",tBefore,tAfter,(tAfter-tBefore),ticksTimeOut,i2c->error);
            i2cDumpI2c(i2c);
            i2cDumpInts(i2c->num);
#endif
        } else { // just a timeout, some data made it out or in.
            reason = I2C_ERROR_TIMEOUT;
            eBits = eBits | EVENT_ERROR_TIMEOUT|EVENT_ERROR|EVENT_DONE;

#if ARDUHAL_LOG_LEVEL >= ARDUHAL_LOG_LEVEL_ERROR
            log_e(" Gross Timeout Dead start=0x%x, end=0x%x, =%d, max=%d error=%d",tBefore,tAfter,(tAfter-tBefore),ticksTimeOut,i2c->error);
            i2cDumpI2c(i2c);
            i2cDumpInts(i2c->num);
#endif
        }
    }

Code that generated the Debug message "injection":

// sync between dispatch(i2cProcQueue) and worker(i2c_isr_handler_default)
typedef enum {
    //I2C_NONE=0,
    I2C_STARTUP=1,
    I2C_RUNNING,
    I2C_DONE
} I2C_STAGE_t;

    if(p_i2c->stage==I2C_DONE) { //get Out
        log_e("eject int=%p, ena=%p",activeInt,p_i2c->dev->int_ena.val);
        p_i2c->dev->int_ena.val = 0;
        p_i2c->dev->int_clr.val = activeInt; //0x1FFF;
        return;
}

As you can see this if() will only trigger if state==I2C_DONE. The only time I have seen this happen was when Wire() was called by multiple task simultaneously. The two hex value printed in the message show the interrupt that generated this call NONE, and the interrupts that are enabled to trigger this ISR NONE. This only happens when code to clear / disable interrupts is called during an active interrupt cycle.

I don't have a clue how the ISR was called out of sequence.

Chuck.

@cyberman54
Copy link
Contributor Author

cyberman54 commented Jul 8, 2018

Hmm, sounds difficult. As my application code runs under espressif32 v1.0.2 without this i2c problem, i assume that this behaviour is caused by something that came in by upgrade Espressif32 to v1.1.x.

In my application code i don't use Wire() directly. But i am using u8g2 library to control an OLED I2C display. The author of u8g2 pointed out, that his library is using Wire.h in Arduino style.

My application uses RTos tasks, but u8g2 calls are centralized in one main task. But the main task will be interrupted by other tasks (which don't call Wire()).

@stickbreaker
Copy link
Contributor

@cyberman54 are you using ANY other i2c code? mixing IDF i2c and Arduino i2c?

Chuck.

@cyberman54
Copy link
Contributor Author

No. Only I2C component is the OLED display, controlled by u8g2 library.

@bartoszbielawski
Copy link

I have exactly the same problem. One I2C display that is controlled from a separate FreeRTOS task.
The class for the display does something and from the same thread I change Wire pin assignments and speed. Otherwise no other accesses.

@stickbreaker
Copy link
Contributor

@cyberman54 @bartoszbielawski are you both using Platformio? I use Arduino. Can either or both of you make a small /simple example that shows this problem?

If I need to set up a Platformio environment I will, but I will probably need some help 😁

Chuck.

@cyberman54
Copy link
Contributor Author

@bartoszbielawski
Copy link

@stickbreaker
Yes, I use PIO as well.
I have already written a minimal test program and I think it should be easy to run it in Arduino IDE:
https://gist.github.com/bartoszbielawski/bf9a03d6eb505b299c7fd6a8b641021c

The screen itself has some extra random dots and the printed number sometime jump few pixels back and forth + the error messages - check the end of the gist.

@stickbreaker
Copy link
Contributor

@bartoszbielawski try changing the xTaskCreate to:


void setup() 
{
    Serial.begin(115200);
    xTaskCreatePinnedToCore(displayThread, "DT", 8192, NULL, 5, NULL,1);    
}

You are starting this task at priority 5, the basic Arduino loop runs at 1. And possibly the interrupt is triggering on the wrong core?

Chuck.

@stickbreaker
Copy link
Contributor

@bartoszbielawski can you make a change in cores\exp32\p32-hal-i2c.c about line 593

   if(p_i2c->stage==I2C_DONE) { //get Out
        log_e("eject int=%p, ena=%p core=%d",activeInt,p_i2c->dev->int_ena.va,xPortGetCoreID());
        p_i2c->dev->int_ena.val = 0;
        p_i2c->dev->int_clr.val = activeInt; //0x1FFF;
        return;
}

Changing the log_e() line to add the coreID.

Chuck.

@bartoszbielawski
Copy link

@stickbreaker
Okay, I have done some tests and here are my conclusions:

  1. it doesn't matter on which code the task runs - I tested it both on core 0 and core 1, the error message always comes from the corresponding core.
  2. (clock rate <= 400 kHz) or (priority == 0) fixes the problem.
  3. For clock rates >= 400 kHz (tested with 800 kHz) priority == 0 helps but the bus is very slow.

I guess I will reduce I2C speed to the regular 400 kHz.
Does it mean that in some cases (clocks >= 400 kHz) the result arrives faster than the software expects it?

@stickbreaker
Copy link
Contributor

@bartoszbielawski let me think about this. So, when you pin it to core1 the Eject says core=1 and if you pin it to core0, eject says core=0.

I have ran my test bed that has 10 i2c devices on a 18" bus at 1,000,000hz for 10k+ operations. But I haven't tried from a separate task, just the prime arduino core.

No, the ISR responds to the interrupts, if they are slower it just takes longer. The ISR is designed to handle concurrent interrupts. the ESP32 won't dispatch while it is in an interrupt.

The Stage==Done is saying Either it completed or a Timeout happened.

another change:
add debug code to display the prior interrupt list:

    if(p_i2c->stage==I2C_DONE) { //get Out
        log_e("eject int=%p, ena=%p",activeInt,p_i2c->dev->int_ena.val);
        i2cDumpInts(p_i2c->num);
        p_i2c->dev->int_ena.val = 0;
        p_i2c->dev->int_clr.val = activeInt; //0x1FFF;
        return;

Chuck

@cyberman54
Copy link
Contributor Author

@stickbreaker I added both of your above debug modifications to esp32-hal-i2c.c and i'm getting this result:

[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0
[E][esp32-hal-i2c.c:1438] i2cDumpInts(): 0 row  count   INTR    TX     RX
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [01] 0x0001 0x0002 0x0003 0x0000 0x000001ad
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x000001ad
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [03] 0x0003 0x0040 0x0000 0x0000 0x000001ae
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0000 0x000001ae
[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0
[E][esp32-hal-i2c.c:1438] i2cDumpInts(): 0 row  count   INTR    TX     RX
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [01] 0x0001 0x0002 0x0003 0x0000 0x00000e80
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x00000e80
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [03] 0x0003 0x0040 0x0000 0x0000 0x00000e81
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0000 0x00000e81
[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0
[E][esp32-hal-i2c.c:1438] i2cDumpInts(): 0 row  count   INTR    TX     RX
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [01] 0x0001 0x0002 0x0003 0x0000 0x00000ed0
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x00000ed0
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [03] 0x0003 0x0040 0x0000 0x0000 0x00000ed1
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0000 0x00000ed1
[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0
[E][esp32-hal-i2c.c:1438] i2cDumpInts(): 0 row  count   INTR    TX     RX
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [01] 0x0001 0x0002 0x0003 0x0000 0x000022ca
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x000022ca
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [03] 0x0003 0x0040 0x0000 0x0000 0x000022cb
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0000 0x000022cb
[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0
[E][esp32-hal-i2c.c:1438] i2cDumpInts(): 0 row  count   INTR    TX     RX
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [01] 0x0001 0x0002 0x000a 0x0000 0x000022ec
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x000022ec
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [03] 0x000a 0x0040 0x0000 0x0000 0x000022ed
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0000 0x000022ed
[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0
[E][esp32-hal-i2c.c:1438] i2cDumpInts(): 0 row  count   INTR    TX     RX
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [01] 0x0001 0x0002 0x000a 0x0000 0x0000232f
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x0000232f
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [03] 0x000a 0x0040 0x0000 0x0000 0x00002330
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0000 0x00002330

@cyberman54
Copy link
Contributor Author

sorry, i forgot the core=%d in the log statement, here we go again:


[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0, core=1
[E][esp32-hal-i2c.c:1438] i2cDumpInts(): 0 row  count   INTR    TX     RX
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [01] 0x0001 0x0002 0x000a 0x0000 0x000001bd
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x000001bd
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [03] 0x000a 0x0040 0x0000 0x0000 0x000001be
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0000 0x000001be
[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0, core=1
[E][esp32-hal-i2c.c:1438] i2cDumpInts(): 0 row  count   INTR    TX     RX
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [01] 0x0001 0x0002 0x000a 0x0000 0x000001df
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x000001df
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [03] 0x000a 0x0040 0x0000 0x0000 0x000001e0
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0000 0x000001e0
[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0, core=1
[E][esp32-hal-i2c.c:1438] i2cDumpInts(): 0 row  count   INTR    TX     RX
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [01] 0x0001 0x0002 0x000a 0x0000 0x00000218
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x00000218
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [03] 0x000a 0x0040 0x0000 0x0000 0x00000219
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0000 0x00000219
[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0, core=1
[E][esp32-hal-i2c.c:1438] i2cDumpInts(): 0 row  count   INTR    TX     RX
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [01] 0x0001 0x0002 0x000a 0x0000 0x00000244
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x00000244
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [03] 0x000a 0x0040 0x0000 0x0000 0x00000245
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0000 0x00000245
[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0, core=1
[E][esp32-hal-i2c.c:1438] i2cDumpInts(): 0 row  count   INTR    TX     RX
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [01] 0x0001 0x0002 0x000a 0x0000 0x00000287
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x00000287
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [03] 0x000a 0x0040 0x0000 0x0000 0x00000288
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0000 0x00000288
[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0, core=1
[E][esp32-hal-i2c.c:1438] i2cDumpInts(): 0 row  count   INTR    TX     RX
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [01] 0x0001 0x0002 0x0003 0x0000 0x000002c8
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x000002c8
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [03] 0x0003 0x0040 0x0000 0x0000 0x000002c9
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0000 0x000002c9
[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0, core=1
[E][esp32-hal-i2c.c:1438] i2cDumpInts(): 0 row  count   INTR    TX     RX
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [01] 0x0001 0x0002 0x0003 0x0000 0x0000233c
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x0000233c
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [03] 0x0003 0x0040 0x0000 0x0000 0x0000233d
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0000 0x0000233d

So, code runs on core1. This is as expected, since i control the i2c display from arduino main loop, and this runs on core1 with RTos.

@cyberman54
Copy link
Contributor Author

And after some seconds i get a Guru Meditation Error:

[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0, core=1
[E][esp32-hal-i2c.c:1438] i2cDumpInts(): 0 row  count   INTR    TX     RX
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [01] 0x0001 0x0002 0x000a 0x0000 0x000030a7
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x000030a7
[D]Guru Meditation Error: Core  1 panic'ed (Interrupt wdt timeout on CPU1)
Core 1 register dump:
PC      : 0x40094a96  PS      : 0x00060534  A0      : 0x80092636  A1      : 0x3ffc0ac0
A2      : 0x3ffd6590  A3      : 0x3ffd8784  A4      : 0x00000001  A5      : 0x00000001
A6      : 0x00060523  A7      : 0x00000000  A8      : 0x3ffd8784  A9      : 0x3ffd8784
A10     : 0x00000019  A11     : 0x00000019  A12     : 0x00000001  A13     : 0x00000001
A14     : 0x00060521  A15     : 0x00000000  SAR     : 0x00000004  EXCCAUSE: 0x00000006
EXCVADDR: 0x00000000  LBEG    : 0x400014fd  LEND    : 0x4000150d  LCOUNT  : 0xfffffffc
Core 1 was running in ISR context:
EPC1    : 0x4000beb4  EPC2    : 0x00000000  EPC3    : 0x4000921a  EPC4    : 0x40094a96

Backtrace: 0x40094a96:0x3ffc0ac0 0x40092633:0x3ffc0ae0 0x400911f7:0x3ffc0b00 0x400d78d0:0x3ffc0b40 0x4018eb2f:0x3ffc0ba0 0x4008638e:0x3ffc0be0 0x400819dd:0x3ffc0c10 0x401b929f:0x00000000

Core 0 register dump:
PC      : 0x40091bde  PS      : 0x00060034  A0      : 0x800922fb  A1      : 0x3ffc0590
A2      : 0x3ffc28d0  A3      : 0x0000cdcd  A4      : 0xb33fffff  A5      : 0x00000001
A6      : 0x00060021  A7      : 0x0000abab  A8      : 0x0000abab  A9      : 0x3ffc0590
A10     : 0x00000003  A11     : 0x00060023  A12     : 0x00060021  A13     : 0x3ffc64c8
A14     : 0x0000002a  A15     : 0x3ffdd8e0  SAR     : 0x00000015  EXCCAUSE: 0x00000006
EXCVADDR: 0x00000000  LBEG    : 0x400014fd  LEND    : 0x4000150d  LCOUNT  : 0xfffffffd

Backtrace: 0x40091bde:0x3ffc0590 0x400922f8:0x3ffc05c0 0x40093487:0x3ffc05e0 0x4009318d:0x3ffc0600 0x400819e6:0x3ffc0610 0x40009217:0x00000000

The dump resolves to:


Decoding 23 results
0x40094a96: vListInsert at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/list.c line 188
0x40094a96: vListInsert at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/list.c line 188
0x40094a96: vListInsert at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/list.c line 188
0x40092633: vTaskPlaceOnEventList at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/tasks.c line 3564
0x400911f7: xQueueGenericReceive at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/queue.c line 2520
0x400d78d0: log_printf at ?? line ?
0x4018eb2f: i2cDumpInts at ?? line ?
0x4008638e: i2c_isr_handler_default at esp32-hal-i2c.c line ?
0x400819dd: _xt_lowint1 at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/xtensa_vectors.S line 1105
0x401b929f: esp_vApplicationWaitiHook at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/freertos_hooks.c line 66
0x40091bde: uxPortCompareSet at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/tasks.c line 3564
:  (inlined by) vPortCPUAcquireMutexIntsDisabledInternal at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/portmux_impl.inc.h line 86
:  (inlined by) vPortCPUAcquireMutexIntsDisabled at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/portmux_impl.h line 98
:  (inlined by) vTaskEnterCritical at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/tasks.c line 4254
0x40091bde: uxPortCompareSet at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/tasks.c line 3564
:  (inlined by) vPortCPUAcquireMutexIntsDisabledInternal at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/portmux_impl.inc.h line 86
:  (inlined by) vPortCPUAcquireMutexIntsDisabled at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/portmux_impl.h line 98
:  (inlined by) vTaskEnterCritical at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/tasks.c line 4254
0x400922f8: xTaskIncrementTick at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/tasks.c line 3564
0x40093487: xPortSysTickHandler at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/port.c line 326 (discriminator 1)
0x4009318d: _frxt_timer_int at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/portasm.S line 303
0x400819e6: _xt_lowint1 at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/xtensa_vectors.S line 1105

@stickbreaker
Copy link
Contributor

@bartoszbielawski

[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0
[E][esp32-hal-i2c.c:1438] i2cDumpInts(): 0 row count INTR TX RX
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [01] 0x0001 0x0002 0x0003 0x0000 0x000001ad
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x000001ad
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [03] 0x0003 0x0040 0x0000 0x0000 0x000001ae
[E][esp32-hal-i2c.c:1442] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0000 0x000001ae

That is weird, nothing is showing up a wrong, just that you are seeing a unserviced interrupt.
That shows a total of 6 interrupts, a TxFifoEmpty, StartTransaction, 3 bytes moved, EndTransaction.

More Debug, lets see the time frame between the last interrupt and this spurious interrupt.

    if(p_i2c->stage==I2C_DONE) { //get Out
        log_e("eject tick=0x%8x int=%p, ena=%p core=%d", xTaskGetTickCountFromISR(),activeInt,p_i2c->dev->int_ena.val,xPortGetCoreID());
        i2cDumpInts(p_i2c->num);
        p_i2c->dev->int_ena.val = 0;
        p_i2c->dev->int_clr.val = activeInt; //0x1FFF;
        return;

Chuck

@stickbreaker
Copy link
Contributor

@bartoszbielawski ignore the core dump, too much debug output during an interrupt, Watchdog died of starvation.

@bartoszbielawski
Copy link

bartoszbielawski commented Jul 8, 2018 via email

@stickbreaker
Copy link
Contributor

@bartoszbielawski Thanks for trying.

Chuck.

@cyberman54
Copy link
Contributor Author

i will check tommorow.

@stickbreaker
Copy link
Contributor

@bartoszbielawski Thru more research we might be having a pullup problem. if this is your board Heltec WiFi kit 32 It shows only 10k pullups on the SDA and SCL lines. Try adding 3.3k pullups. That should drop the effective pullups to 2.3k. We might be having pullup issues at higher data rates.

Chuck.

@cyberman54
Copy link
Contributor Author

@bartoszbielawski does is work with Espressif32 v1.0.2 and same.board?

@stickbreaker SDA/SCL are muxed in the ESP32 and can be switched to different GPIOs

@bartoszbielawski
Copy link

@cyberman54 It does work on 1.0.2 on the same board.
@stickbreaker I could understand the problem happens due to weak pull-ups but how does setting priority of the task to 0 fix the problem? I'm willing to tinker with the board but I don't have access to my lab at the moment.

@helmut64
Copy link

Hi Chuck, I have seen in the Adafruit_Si7021 multiple Wire.endTransmission(false), without a reason for the false. I removed the false parameter and the I2C works again.

I will continue testing with your patch.

@helmut64
Copy link

Update:
The new Pull request #1665 does not work with the Adafruit_Si7021 I2C driver (no Wire.endTransmission false used).
Without this patch it works (without the Wire.endTransmission false parameter).

@stickbreaker
Copy link
Contributor

@helmut64 are you seeing any error messages?
Post a link to the library you are using. I'll look through it.

Chuck.

@helmut64
Copy link

The Adafruit_Si7021 is very simple, the code is here: https://github.com/adafruit/Adafruit_Si7021
PS: When I switch your code to Debug-Lebel Verbose there are problems in the log_e code and it does not compile.
Helmut

@stickbreaker
Copy link
Contributor

@helmut64 Post the compile errors, I can't fix what I can't see.

Looking through that si7021 library, I can see why it doesn't work.
Original AdaFruit code

float Adafruit_Si7021::readHumidity(void) {
  Wire.beginTransmission(_i2caddr);
  Wire.write((uint8_t)SI7021_MEASRH_NOHOLD_CMD);
  Wire.endTransmission(false);
  delay(25);

  Wire.requestFrom(_i2caddr, 3);
  uint16_t hum = Wire.read();
  hum <<= 8;
  hum |= Wire.read();
  uint8_t chxsum = Wire.read();

  float humidity = hum;
  humidity *= 125;
  humidity /= 65536;
  humidity -= 6;

  return humidity;
}

This code will not react as assumed. The i2c subsystem will queue the Wire.endTransmission() delay for 25ms then do the Wire.requestFrom() which will return a NAK, without any data being transferred.

  Wire.endTransmission(false);
  bool done = false;
  uint32_t timeout = millis();
  while((millis()-timeout<1000)&&( !done)){ // 1sec timeout
    done = (Wire.requestFrom(_i2caddr, 3) ==3);
    delay(2); // give other tasks a bit of time while sensor samples
  }
  if (done){
    uint16_t hum = Wire.read();
    hum <<= 8;
    hum |= Wire.read();
    uint8_t chxsum = Wire.read();

    float humidity = hum;
    humidity *= 125;
    humidity /= 65536;
    humidity -= 6;

    return humidity;
  }
  else { // error
    return -1.0; // error    
  }
}

This is only one problem, there are more, when I get a chance I'll go through the rest of the library.

Chuck.

@helmut64
Copy link

The Compiler problem you see only when you switch within the Arduino IDE the menu the "Core Debug-Level" level to Verbose and click on compile.

@stickbreaker
Copy link
Contributor

@helmut64 It compiles without any errors on my system using Arduino 1.8.5, Core Debug Level NONE -> VERBOSE .

I'm not seeing any problems, capture the Arduino's compile window. Without it I can't do anything.

Chuck.

@stickbreaker
Copy link
Contributor

@helmut64 I modified Adafruit's si7021 library here. It should now work with esp32. It compiles, but I don't have one of these sensors, so it may not actually function. Try it an report any problems.

Chuck.

@stickbreaker
Copy link
Contributor

@cyberman54 If this fix works for you, close this issue. me-no-dev just merged it into the main repo. So, lets see if any new errors crop up.

Chuck.

@cyberman54
Copy link
Contributor Author

cyberman54 commented Jul 24, 2018

@stickbreaker meanwhile i did some tests with my app, comparing running it unter Espressif 1.0.2 and Espressif 1.1.2 including latest pull requests, also yours. Result is:

  • I don't see any more i2c errors, not on log level info and not on log level debug, while running OLED display with u8g2 driver @ 400 KHz. So far looking good.
  • But the performance of display refresh and other functions of my app still are significantly slowed down by unknown resson. My app blinks a LED in different flash cycles depending on device status. With 1.1.2 the device is too slow to see short blinks of 50ms, while this works with 1.0.2
  • Device functions, including display refresh, sometimes seem to freeze for short time, maybe 50 - 100 milliseconds. This could point to an interrupt problem. I currently have now idea how to debug this, since i'm still not into JTAG debugging.

So, result is that i will continue sticking to Espressif core 1.0.2, until i get rid this performance hit :-(

@cyberman54
Copy link
Contributor Author

@stickbreaker i did another test and took out the display driver from my app, so that no i2c communication is used. Result is, that the performance issues disappear, i.e. LED blinking is back to normal.
This may be a hint that there is still a problem in the i2c subsystem, maybe some sort of interrupt cascade. But i am far away from being sure, because i have only very limited debug options yet.

@stickbreaker
Copy link
Contributor

@cyberman54 can you post your display driver code? I need something to test.

ssd1306_128x64_i2c.zip
SSD1306.zip

The SSD1306.zip is a modified AdaFruit_SSD1306 that only sends changed bits to the display.
The ssd1306_128x64_i2c.zip has some performance monitoring in it. It needs Adafruit_GFX, and AdaFruit_SSD1306. You can change the comments to switch to my SSD1306 to see the difference.

One of the tests "testStar()" takes 3610ms using Adafruit_SSD1306 only 865ms with SSD1306.

Have you went through your U8X8_SSD1306_128X64_NONAME_HW_I2C verifying that it handles ReSTARTS correctly?
The esp32 hardware handles ReSTARTS differently than AVR (standard Arduino). Possibly the library is having issues.

Chuck.

@cyberman54
Copy link
Contributor Author

@stickbreaker i'm using u8x8.cpp from the u8g2 library. Did not write any display driver code on my own.

@stickbreaker
Copy link
Contributor

@cyberman54 can you give me a basic sketch that uses this library? Looking through this code is a nightmare. I need a place to start.

Chuck.

@helmut64
Copy link

helmut64 commented Jul 25, 2018

The Updated SI7021 Sensor library works, I understand your while loop around the Wire.requestFrom().
However I believe it still has problems:

  • The old readHumidity() was waiting 20ms which is the time the temperature conversion needs in the device, if this delay is not included I believe the previous temperature is being returned, the same for readTemperature. Maybe I am wrong here.
  • The read sensor moden and revision function is gone. (API incompatibility).

Thank you for helping out here.
Helmut

@stickbreaker
Copy link
Contributor

@helmut64 my timing was taken from here:
si7021_timing
And the NAK protocol from here:
si7021_nak

I don't know what you meant here:

The read sensor moden and revision function is gone. (API incompatibility).

I don't have one of these sensors, so I am basing my code on my understanding of the datasheet. I guess, if my code doesn't fit your purpose you'll have to write better code 😀

If you have a library that produces accurate values, just modify it to work with the esp32.

Chuck.

@helmut64
Copy link

Chuck, you do a great job, and I love to see better I2C support, thank you for your support.

I was talking about the missing functions:

Adafruit_Si7021::readRevision and the variable “model”.

I will do further testing and integrate your changes.

You need a set of our ESP32 ECO Power boards with the sensor, please contact me (via the radioshuttle.de website) with your contact details.
Helmut

@stickbreaker
Copy link
Contributor

@helmut64 just tried the contact link from your website

This message was created automatically by the mail system (ecelerity).

A message that you sent could not be delivered to one or more of its
recipients. This is a permanent error. The following address(es) failed:

[email protected] (after RCPT TO): 550 5.1.1 [email protected]: Recipient address rejected: >User unknown in virtual alias table

substituted "XXXXXXXX" to protect you address

Chuck.

@helmut64
Copy link

helmut64 commented Jul 27, 2018

@stickbreaker [email protected] should work.

@helmut64
Copy link

Hi Chuck, I have another problem with I2C using the Rodan DS3231 RTC driver. The driver is not great, no C++, however it works with D21 MCUs and well with AVRs, it was working with the ESP32 until your patch.
https://github.com/helmut64/ds3231/tree/ESP_ECO_POWER_RTC

There is no endTransmission(false) in this, I plan to use a scope to trace what is going on. Maybe you see something and can point to it.
Regards Helmut

@stickbreaker
Copy link
Contributor

@helmut64 that is the email i used.
I'll try it again.

On the Rtc, I'll look at it tomorrow or saturday. Today was 20+ hrs I'm blitzed.

Chuck

@stickbreaker
Copy link
Contributor

@helmut64 got it.

@helmut64
Copy link

helmut64 commented Aug 6, 2018

FYI: For the Rodan DS3231 library I fixed the I2C ESP32 support, basically via a timeout loop around the Wire.requestFrom() as proposed by you. A "Wire.available()" check is an alternate option I tested, however the timeout loop is better because it avoids hangs. The new Rodan DS3231 library (tested on ARV, D21 and ESP32) is available now.
Regards
Helmut

stickbreaker added a commit to stickbreaker/arduino-esp32 that referenced this issue Sep 20, 2018
espressif#1869 exposed a resource exhaustion issue. The current HAL layer for I2C support is designed to use a shared interrupt, But, during debugging to solve the interrupt overloading condition identified in espressif#1588, and the generation of pr espressif#1717, the interrupt allocation parameters were changed.  This change was unnecessary, the code will work successfully with shared interrupts.  So, there is no need to assign a private interrupt for each I2C peripheral.
me-no-dev pushed a commit that referenced this issue Sep 21, 2018
#1869 exposed a resource exhaustion issue. The current HAL layer for I2C support is designed to use a shared interrupt, But, during debugging to solve the interrupt overloading condition identified in #1588, and the generation of pr #1717, the interrupt allocation parameters were changed.  This change was unnecessary, the code will work successfully with shared interrupts.  So, there is no need to assign a private interrupt for each I2C peripheral.
@copercini
Copy link
Contributor

Fixed on #1767 =)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

8 participants