i2c_master_cmd_begin() and error code 263 (timeout)

[andreko]

here is the summary of my timeout trials from today. I found a section in the ESP8694(C2) reference manual:

21.4.7 Timeout Control
The I2C master controller has three types of timeout control, namely timeout control for SCL_FSM, for
SCL_MAIN_FSM, and for the SCL line. The first two are always enabled, while enabling the third is
configurable.
When SCL_FSM remains unchanged for more than 2I2C_SCL_ST_TO_I2C clock cycles, an I2C_SCL_ST_TO_INT
interrupt is triggered, and then SCL_FSM goes to idle state. The value of I2C_SCL_ST_TO_I2C should be less
than or equal to 22, which means SCL_FSM could remain unchanged for 222 I2C_SCLK clock cycles at most
before the interrupt is generated.
When SCL_MAIN_FSM remains unchanged for more than 2I2C_SCL_MAIN_ST_TO_I2C clock cycles, an
I2C_SCL_MAIN_ST_TO_INT interrupt is triggered, and then SCL_MAIN_FSM goes to idle state. The value of
I2C_SCL_MAIN_ST_TO_I2C should be less than or equal to 22, which means SCL_MAIN_FSM could remain
unchanged for 222 I2C_SCLK clock cycles at most before the interrupt is generated.
Timeout control for SCL is enabled by setting I2C_TIME_OUT_EN. When the level of SCL remains unchanged for
more than I2C_TIME_OUT_VALUE clock cycles, an I2C_TIME_OUT_INT interrupt is triggered, and then the I2C
bus goes to idle state.

NOTE: formatting of the text above is incorrect, check the original doc to not get confused with the numbers.

I tried to set the values for I2C_SCL_MAIN_ST_TO_I2C and I2C_SCL_ST_TO_I2C to the maximum of 22 and did not get any improvement, except that the timeout might come later.

I also changed the timeout value to the maximum of 0x1F via i2c_set_timeout() and finally disabled the timeout at all. It is enabled by default in i2c_ll.h line #166 in my version of the IDE.

Both did not solve the problem, it just changed the timing of the event.

No ideas at the moment, except to step through the code to understand why smaller I2C payload work and larger not.

[RobMeades]

Good try with experimenting with the I2C timeouts, at least we have attempted that.

I have now run my tests on an ESP32-S3 Devkit board and the outcome is the same as it is on our own HW. Probing the I2C bus, it seems as though the ESP32-S3 is simply choosing not to continue clocking the bus.

Here is a complete Saleae trace of the entire test suite that we run (about 6 minutes), which passes perfectly with ESP32, where the red line indicates that i2c_master_cmd_begin() is running, the blips on the orange and yellow lines indicate that a timeout error has been returned by i2c_master_cmd_begin() (orange for when the ESP32-S3 is doing a "send" to the device, yellow when the ESP32-S3 is doing a "receive" from the device) and a blip on the green line indicates that "no ack from device" has been returned by i2c_master_cmd_begin():

i2c_esp32s3_overall.png (110.44 KiB) Viewed 4027 times

Zooming in on the first error, an error on send:

i2c_esp32s3_send.png (72.9 KiB) Viewed 4027 times

...you can see that a write has been set up to address 0x42 and the device has acked it (at least as far as the Saleae probe can tell) but then there is no clocking for the rest of the write, which I guess results in the timeout. All of the timeout errors on send, the yellow blips, look like this.

Zooming in on the second error, an error on receive:

i2c_esp32s3_receive.png (97.18 KiB) Viewed 4027 times

...again, the Saleae probe believes that a read has been set up to address 0x42 and the first byte (which is all zeroes) has been received and acked but then the clock stops again and i2c_master_cmd_begin() returns timeout. Curiously, 16 ms later, and not while i2c_master_cmd_begin() is running, the clock returns high, which the slave probably sees as a signal to get on with things and pulls the data bus low, but then the clock stays high. In some cases this confuses the devil out of the bus and results in a nack the next time. All of the timeout errors on receive, the orange blips, look like this.

I believe these traces look very similar to yours @andreko, though in my case I can't say they are related to data length.

In order that we get some attention from an Espressif person, I have raised this on their Github issues here:

https://github.com/espressif/esp-idf/issues/11397

Let's see what they say.

[MicroController]

Just another thought: Signal integrity/rise-/fall times. Won't see it on an LA.

As I think I said above, the symptoms (clock stopping + timeout error) are consistent with a "stuck" FSM, which I believe can happen if the I2C controller sees signalling it does not expect. E.g. if the SDA line would change levels too slowly, the controller could interpret that as an out-of-order start or stop condition.

If you haven't done so, it may be worth checking out the glitch filter settings of the I2C controller.
And there is the "I2C_SDA_SAMPLE_REG", which says "This field is used to configure how long SDA is sampled". Don't know what that is supposed to mean, but it might refer to the time between rising SCL and sampling SDA. You may want to experiment with that register too.

[RobMeades]

Yeah, saw those fields but didn't fancy poking around in the dark; I guess there must be an explanation of how one is supposed to approach them somewhere? Must admit it seems strange to have to fiddle with them though, when I've never had to do anything like that with any other chipset and the Saleae probe is seeing an "ack". Surely ESP32-S3 can't be that sensitive?

[MicroController]

I figure that possibly the default timings of the I2C controller are different between SoCs, in addition to maybe voltage thresholds.
But I agree that there definitely should be at least some more meaningful documentation of the parameters and configuration.
I probably would be poking around in the dark, trying to "reverse engineer" what's what, while waiting for the issue at github to be addressed - but that's only me

[andreko]

@RobMeades thanks for sharing the analysis. Somehow it seems different from my case, I only see the issue with longer payloads on the bus. All short data communications seems to work as expected. I tried all recommendations from the github issue, but it did not solve the problem.

[RobMeades]

@andreko: agreed that it might turn out to be different but it seems that things are washing around somewhat in the ESP-IDF I2C world so it is certainly worth you watching what's going on; no harm in you raising your problem as a separate case though.

@microcontroller: talking with Espressif support it doesn't _seem_ to be an electrical issue from what we can tell but there is certainly evidence that the correct I2C timings, from an S3 perspective at least, are still not quite settled.

[RobMeades]

For the benefit of anyone who gets here, after a few days of conversation with an _extremely_ helpful and knowledgeable Espressif engineer, we figured out what was going on, details here: https://github.com/espressif/esp-idf/issues/11397 but in summary the value passed to `i2c_set_timeout()` in ESP32 is a multiplier on the 80 MHz APB clock but on the ESP32S3 it is NO LONGER THAT SIMPLE, the value is instead a power of two times either the XTAL (40 MHz) or, if you have selected it, the RC network (17.5 MHz) clock period. So:

ESP32S3: timeout = 2^x * (1/40000000)

...which is how they can get away with having a 5-bit timeout register. The technical reference manual and ESP-IDF documentation don't really make this switcheroo clear, be warned!

We set a timeout of 10 ms because the GNSS device we're talking to over I2C can be very busy, especially as it is booting; I thought the I2C timeout worked the same as ESP32, which in 5 bits means a max value of 0.38 microseconds, so I was just leaving it set to the default as I thought it was of no practical use; the default value of 12 works out to 2^12 * (1/40000000) = 102 microseconds, which is not quite enough when talking to a very busy GNSS device. Now that I understand what's going on I can in can set it to 19 instead of 12 to get the desired effect; my instability goes away.

[RobMeades]

@andreko worth you checking if this is an issue for you as the C3 is the same.