I2C Interrupt problem since uprade espressif32 core to v1.1.0 #107

cyberman54 · 2018-07-04T06:51:06Z

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.3 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 · 2018-07-04T07:03:20Z

Some more error information, gathered in log level debug:


[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0
[E][esp32-hal-i2c.c:997] i2cProcQueue(): TimeoutRecovery: expected=0ms, actual=2ms
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): i2c=0x3ffc35c8
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1425] i2cDumpI2c(): lock=0x3ffd6858
[E][esp32-hal-i2c.c:1427] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): event=0x3ffd68dc bits=10
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): intr_handle=0x3ffd690c
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): dq=0x3fff3cac
[E][esp32-hal-i2c.c:1434] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1435] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1436] i2cDumpI2c(): byteCnt=3
[E][esp32-hal-i2c.c:1393] i2cDumpDqData(): [0] 78 W STOP buf@=0x3ffcbb4e, len=2, pos=2, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1411] i2cDumpDqData(): 0x0000: ..                               00 08
[E][esp32-hal-i2c.c:1446] i2cDumpInts(): 0 row  count   INTR    TX     RX
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [01] 0x0001 0x0002 0x0003 0x0000 0x000027ba
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x000027ba
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [03] 0x0003 0x0040 0x0000 0x0000 0x000027ba
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0000 0x000027ba

atanisoft · 2018-07-04T13:55:10Z

this should be reported against arduino-esp32 instead of platformio-espressif32. With the new arduino code picked up in 1.1.0 there is new i2c code which it appears you are hitting an issue with, @stickbreaker would be able to decipher the log statements you have above and point you in the right direction of a solution.

stickbreaker · 2018-07-04T15:39:44Z

@cyberman54 update to the latest core, The timeout Recovery is just a debug message, either updated to the newest core or reduce your Core Debug level to ERROR.

The Injection Error is triggering because an I2c Interrupt was triggered without the ISR being configured. This has only been caused by multi-threading Wire(). Wire() is not designed to handle being called from multiple tasks.

The slowdown you are noticing is because of the delay caused by the debug output.

Chuck.

cyberman54 · 2018-07-04T16:42:39Z

Thanks for explanation.
If i reduce log level to INFO or ERROR is still see lots of injection error messages.
If i reduce log level to NONE to suppress the output of those error messages, i still see a huge slowdown of display refresh, what i assume is caused by data transmission errors or timeouts on the I2C bus?

The same display code performed without issues with former version 1.0.3.

stickbreaker · 2018-07-04T17:15:20Z

@cyberman54 Please post a capture of the error log with Core Debug Level at DEBUG.

Have you checked for multi-tasking of Wire()?

Every time one of those injection Errors are seen, an i2c transmission has been aborted. I would suspect that is the genesis of the reduced performance.

Chuck.

cyberman54 · 2018-07-04T19:06:48Z

Chuck, thanks for your support here!

Below you find my error log. These errors repeat a lot, no doubt this will be the reason why the display speed slows down. I'm using u8g2 Library, which depends, as far as i see, one Wire.h.

I'm using RTos for parallel tasking in an ESP32 arduino framework. The display (and so, the I2c) control is centralized in one task, but this tasks sure gets interrupts by other RTos tasks. So i assume i run in that multi-tasking problem with Wire().

But how could i solve this? Again, with arduino-espressif32 v1.0.3 the i2c ran smooth.

--


[E][esp32-hal-i2c.c:997] i2cProcQueue(): TimeoutRecovery: expected=0ms, actual=2ms
[E][esp32-hal-i2c.c:1422] i2cDumpI2c(): i2c=0x3ffc35c8
[E][esp32-hal-i2c.c:1423] i2cDumpI2c(): dev=0x60013000 date=0x16042000
[E][esp32-hal-i2c.c:1425] i2cDumpI2c(): lock=0x3ffd66dc
[E][esp32-hal-i2c.c:1427] i2cDumpI2c(): num=0
[E][esp32-hal-i2c.c:1428] i2cDumpI2c(): mode=1
[E][esp32-hal-i2c.c:1429] i2cDumpI2c(): stage=3
[E][esp32-hal-i2c.c:1430] i2cDumpI2c(): error=1
[E][esp32-hal-i2c.c:1431] i2cDumpI2c(): event=0x3ffd6760 bits=10
[E][esp32-hal-i2c.c:1432] i2cDumpI2c(): intr_handle=0x3ffd6790
[E][esp32-hal-i2c.c:1433] i2cDumpI2c(): dq=0x3ffe21a4
[E][esp32-hal-i2c.c:1434] i2cDumpI2c(): queueCount=1
[E][esp32-hal-i2c.c:1435] i2cDumpI2c(): queuePos=0
[E][esp32-hal-i2c.c:1436] i2cDumpI2c(): byteCnt=10
[E][esp32-hal-i2c.c:1393] i2cDumpDqData(): [0] 78 W STOP buf@=0x3ffcbb4e, len=9, pos=9, eventH=0x0 bits=0
[E][esp32-hal-i2c.c:1411] i2cDumpDqData(): 0x0000: @.<JJJJ0.                        40 00 3c 4a 4a 4a 4a 30 00
[E][esp32-hal-i2c.c:1446] i2cDumpInts(): 0 row  count   INTR    TX     RX
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [01] 0x0001 0x0002 0x000a 0x0000 0x0000307e
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [02] 0x0001 0x0200 0x0000 0x0000 0x0000307e
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [03] 0x000a 0x0040 0x0000 0x0000 0x0000307f
[E][esp32-hal-i2c.c:1450] i2cDumpInts(): [04] 0x0001 0x0080 0x0000 0x0000 0x0000307f

stickbreaker · 2018-07-04T20:43:17Z

@cyberman54 This error log you just posted is from a prior version of the Arduino Core, This message is not in the current core. me-no-dev merged this pr 1574 two days ago.

Updating to the current core will prevent this debug message from being emitted. It was just code to see if the ISR correctly handled a SCL stretching event.

Your debug output shows that it was delayed 2ms, probably by interrupt latency, WiFi has higher priority.

I'm using RTos for parallel tasking in an ESP32 arduino framework. The display (and so, the I2c) control is centralized in one task, but this tasks sure gets interrupts by other RTos tasks. So i assume i run in that multi-tasking problem with Wire().

But how could i solve this? Again, with arduino-espressif32 v1.0.3 the i2c ran smooth.

As long as Wire() calls are not being simultaneously being called from multiple tasks, Wire() can be used in multiple tasks. You just have to Guarantee that all calls to Wire() are serialized:

task 1 uses Wire() for some task. (complete calls) ->
Wire.beginTransmission(),Wire.write(),Wire.endTransmission()
Wire.requestFrom(). Wire.read()
task 2 can now use Wire(), but task1 cannot reuse any Wire() calls until task 2 has finished the transmission.

This debug output is causing the performance issue you are seeing. By updating to the newest core, this penalty will no longer be incurred. This debug message was removed 07/04/2018

Chuck.

cyberman54 · 2018-07-04T20:59:01Z

Chuck, thanks for the explanation. I switched my PlatformIO IDE to the staging version of arduino-espressif32, but it seems your pull request has not yet arrived there. So i now will wait some days.

cyberman54 · 2018-07-08T13:46:08Z

I still get the error, after i switched to arduino staging environment and did a pio update.
How can i make sure that my arduino-framework has the commit by chuck inside?

ivankravets · 2018-07-08T14:24:43Z

Is it fixed in master branch?

cyberman54 · 2018-07-08T14:42:39Z

yes:
espressif/arduino-esp32#1574

ivankravets · 2018-07-08T14:44:08Z

Did you try to clean project?

cyberman54 · 2018-07-08T14:49:36Z

yes, and i several times installed and uninstalled Espressif32 platform.
How can i clean this up?

ivankravets · 2018-07-08T14:50:25Z

Try to remove ~/.platformio/packages/framework-arduinoesp32....

cyberman54 · 2018-07-08T14:53:05Z

I did that. Then did a install via library manager, Espressif32 v1.1.2, but after this i found in
~/.platformio/packages/framework-arduinoesp32....
a version which does not have the Pullrequest for the i2c problem inside.

ivankravets · 2018-07-08T15:22:43Z

Let's wait for @stickbreaker comment.

cyberman54 · 2018-07-08T15:34:25Z

I think it's some problem with my local PlatformIO installation.
So this is side effect, not affecting the original issue.

ivankravets · 2018-07-08T16:05:11Z

Does it work now?

cyberman54 · 2018-07-08T16:38:20Z

I got the actual arduino-espressif32 core installed, and as Chuck pointed out, the debug messages are gone.

But the primary problem with missed i2c interrupts

[E][esp32-hal-i2c.c:594] i2c_isr_handler_default(): eject int=0x0, ena=0x0

still persist and performance of OLED display is very low. The same code runs with espressif32 core 1.0.3 without issues. Something with i2c must have been changed?

stickbreaker · 2018-07-08T16:40:01Z

@ivankravets if @cyberman54 is still seeing 'timeout recovery' he is using stale code.

Chuck.

ivankravets · 2018-07-08T16:43:44Z

We don't develop ESP32 Core for Arduino. Please report all issues to https://github.com/espressif/arduino-esp32/issues and inform us here when we will need to make a new release.

cyberman54 · 2018-07-08T16:57:47Z

For the PlatformIO part: for me it looks like platformio cannot handle different arduino-espressif32 cores in path packages?

ivankravets · 2018-07-08T16:59:40Z

Please share a content of your platformio.ini.

cyberman54 · 2018-07-08T18:15:47Z

https://github.com/cyberman54/ESP32-Paxcounter/blob/development/platformio.ini

ivankravets · 2018-07-09T09:57:25Z

Are you sure that platform = https://github.com/platformio/platform-espressif32.git#feature/stage does not work for you? I mean, are you sure that it does not use the latest source code of Arduino Core for ESP32 from upstream repo?

cyberman54 · 2018-07-09T10:10:18Z

@ivankravets it seems to work now, after i had some sort of trouble with different versions of arduino-espressif32 on my disk.

Let us focus on the i2c problem here now, this is the basic issue.

cyberman54 mentioned this issue Jul 4, 2018

[ESP32] I2C Interrupt problem since uprade to Espressif 1.1.0 espressif/arduino-esp32#1588

Closed

cyberman54 mentioned this issue Jul 4, 2018

i2c Write Issue espressif/arduino-esp32#834

Closed

ivankravets closed this as completed Jul 8, 2018

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

I2C Interrupt problem since uprade espressif32 core to v1.1.0 #107

I2C Interrupt problem since uprade espressif32 core to v1.1.0 #107

cyberman54 commented Jul 4, 2018

cyberman54 commented Jul 4, 2018

atanisoft commented Jul 4, 2018

stickbreaker commented Jul 4, 2018 •

edited

Loading

cyberman54 commented Jul 4, 2018

stickbreaker commented Jul 4, 2018

cyberman54 commented Jul 4, 2018 •

edited

Loading

stickbreaker commented Jul 4, 2018

cyberman54 commented Jul 4, 2018

cyberman54 commented Jul 8, 2018

ivankravets commented Jul 8, 2018 •

edited

Loading

cyberman54 commented Jul 8, 2018

ivankravets commented Jul 8, 2018

cyberman54 commented Jul 8, 2018

ivankravets commented Jul 8, 2018

cyberman54 commented Jul 8, 2018

ivankravets commented Jul 8, 2018

cyberman54 commented Jul 8, 2018

ivankravets commented Jul 8, 2018

cyberman54 commented Jul 8, 2018

stickbreaker commented Jul 8, 2018

ivankravets commented Jul 8, 2018

cyberman54 commented Jul 8, 2018

ivankravets commented Jul 8, 2018

cyberman54 commented Jul 8, 2018

ivankravets commented Jul 9, 2018

cyberman54 commented Jul 9, 2018

I2C Interrupt problem since uprade espressif32 core to v1.1.0 #107

I2C Interrupt problem since uprade espressif32 core to v1.1.0 #107

Comments

cyberman54 commented Jul 4, 2018

cyberman54 commented Jul 4, 2018

atanisoft commented Jul 4, 2018

stickbreaker commented Jul 4, 2018 • edited Loading

cyberman54 commented Jul 4, 2018

stickbreaker commented Jul 4, 2018

cyberman54 commented Jul 4, 2018 • edited Loading

stickbreaker commented Jul 4, 2018

cyberman54 commented Jul 4, 2018

cyberman54 commented Jul 8, 2018

ivankravets commented Jul 8, 2018 • edited Loading

cyberman54 commented Jul 8, 2018

ivankravets commented Jul 8, 2018

cyberman54 commented Jul 8, 2018

ivankravets commented Jul 8, 2018

cyberman54 commented Jul 8, 2018

ivankravets commented Jul 8, 2018

cyberman54 commented Jul 8, 2018

ivankravets commented Jul 8, 2018

cyberman54 commented Jul 8, 2018

stickbreaker commented Jul 8, 2018

ivankravets commented Jul 8, 2018

cyberman54 commented Jul 8, 2018

ivankravets commented Jul 8, 2018

cyberman54 commented Jul 8, 2018

ivankravets commented Jul 9, 2018

cyberman54 commented Jul 9, 2018

stickbreaker commented Jul 4, 2018 •

edited

Loading

cyberman54 commented Jul 4, 2018 •

edited

Loading

ivankravets commented Jul 8, 2018 •

edited

Loading