I2C issues: Sometimes write instead of read is emitted #4779
Description
Hello,
I am using a DS3231 RTC to keep the date and time in my application. I am experiencing I2C issues with my setup.
Hardware:
Board: ESP WROVER KIT / ESP32-WROVER-E (16MB)
Core Installation version: platformio/framework-arduinoespressif32 @ 3.10004.210126
IDE name: PlatformIO 5.1 / CLion
Flash Frequency: 40MHz
PSRAM enabled: ?
Upload Speed: 115200
Computer OS: Windows 10 / macOS 10.15.7
Description:
The ESP32 is supposed to sleep, wake up after some time, get the current time from the RTC, do something, go back to sleep. And repeat and repeat. It is possible to enable the webserver after a cycle to do diagnostics etc from a webpage. As webserver I am using the Async Webserver.
For development I use macOS as well Windows computers. I build my code with the help of PlatformIO 5.1, on some devices with CLion on others with VSCode.
The following libraries are relevant:
- OneWire @ 2.3.5
- Adafruit RTCLib @ 1.11.3
- platformio/framework-arduinoespressif32 @ 3.10004.210126
- platformio/espressif32 @ 3.0.0
Most of the sleep->wakeup->sleep cycles work well. The time from RTC is read correctly and everything is fine. But at very few cycles the I2C communication get's completely wrong in a dangerous way. Instead of a "Read" command a "Write" command is sent.
Debug Messages:
Usually the communication should look like this:
08:31:54.272 > [E][esp32-hal-i2c.c:1058] i2cAddQueue(): Write OP before AddQueue! Addr: 104, Data (source): 00 , Len: 1
08:31:54.272 > [E][esp32-hal-i2c.c:1093] i2cAddQueue(): Setting mode in queue to W
08:31:54.272 > [E][esp32-hal-i2c.c:1132] i2cAddQueue(): Write OP after AddQueue! Addr: 104, Data (source): 00 , Len: 1
08:31:54.272 > [E][esp32-hal-i2c.c:697] fillTxFifo(): Writing mode to i2c: W
08:31:54.272 > [E][esp32-hal-i2c.c:721] fillTxFifo(): Writing data to tx: 0
08:31:54.272 >
08:31:54.272 > [E][esp32-hal-i2c.c:1068] i2cAddQueue(): Read OP before AddQueue! Addr: 104, Data (target -> data nonsense): 00 00 00 00 00 00 00 , Len: 7
08:31:54.272 > [E][esp32-hal-i2c.c:1093] i2cAddQueue(): Setting mode in queue to R
08:31:54.272 > [E][esp32-hal-i2c.c:1142] i2cAddQueue(): Read OP after AddQueue! Addr: 104, Data (target -> data nonsense): 00 00 00 00 00 00 00 , Len: 7
08:31:54.272 > [E][esp32-hal-i2c.c:697] fillTxFifo(): Writing mode to i2c: R
08:31:54.272 > [E][esp32-hal-i2c.c:815] emptyRxFifo(): Emptied RX buffer! Data: 52 35 19 4 7 1 33 , Len: 7
In some situations the following occurs:
08:32:47.580 > [E][esp32-hal-i2c.c:1058] i2cAddQueue(): Write OP before AddQueue! Addr: 104, Data (source): 00 , Len: 1
08:32:47.580 > [E][esp32-hal-i2c.c:1093] i2cAddQueue(): Setting mode in queue to W
08:32:47.580 > [E][esp32-hal-i2c.c:1132] i2cAddQueue(): Write OP after AddQueue! Addr: 104, Data (source): 00 , Len: 1
08:32:47.580 > [E][esp32-hal-i2c.c:697] fillTxFifo(): Writing mode to i2c: W
08:32:47.580 > [E][esp32-hal-i2c.c:721] fillTxFifo(): Writing data to tx: 0
08:32:47.580 >
08:32:47.580 > [E][esp32-hal-i2c.c:1068] i2cAddQueue(): Read OP before AddQueue! Addr: 104, Data (target -> data nonsense): 88 36 45 01 09 02 21 , Len: 7
08:32:47.580 > [E][esp32-hal-i2c.c:1093] i2cAddQueue(): Setting mode in queue to R
08:32:47.580 > [E][esp32-hal-i2c.c:1142] i2cAddQueue(): Read OP after AddQueue! Addr: 104, Data (target -> data nonsense): 88 36 45 01 09 02 21 , Len: 7
08:32:47.580 > [E][esp32-hal-i2c.c:697] fillTxFifo(): Writing mode to i2c: R
08:32:47.580 > [E][esp32-hal-i2c.c:815] emptyRxFifo(): Emptied RX buffer! Data: FF FF FF FF FF FF FF , Len: 7
From the driver logging it looks like there was a "Read" command and the received data contains only FF. But that was not the case.
With a logic analyzer the communication looks like this:
My logging shows the driver is expecting to write a "read" command but actually writing a "write" command.
I've added some custom logging to the esp32-hal-i2c.c because the big debug logging changes some timing in a way that the error does not occur anymore.
In my application I can reproduce it best when I send a request to the Async Webserver requesting the RTC time soon after a reset of the device.
This is the modified driver I've used with the logging. It's easier to understand the log with it probably.
esp32-hal-i2c.c.txt
Reproducing
Reproducing is probably difficult because you need the same RTC and I need to extract the minimal example from my application. If we need reproduce it with a minimal example, I can try to create one. But maybe debugging on my side + logs are helpful enough to find the error already.
I would be very glad if someone can have a look.
Thanks a lot in advance!