machine/esp32xx: fix I2C NACK handling and controller hang after an address NACK

[0hJonny]

Fixes #5767.

This is the esp32xx part of #5585. Its direct copy was reverted in #5602. Tested on ESP32-S3 (LILYGO T5-4.7-S3) with a GT911 at 0x5D and a PCF8563 at 0x51 on I2C0 at 400 kHz.

Changes

1. No ack_check_en on READ commands. With it, a successful read raised NACK_INT together with TRANS_COMPLETE (seen with the same commands written directly to the registers: all commands done, correct data, INT_RAW 0x8692). && !readLast ignored NACK in reads, so a read from an absent device returned nil. ESP-IDF does not set ack_check_en on reads (i2c_master_read_static in driver/i2c.c).

2. The address byte in its own WRITE command, followed by END. When the address and the data were one WRITE command and the address got a NACK, every following transaction ran only START and failed until the next Configure. With the address in its own WRITE plus END, the next transaction works without a reset. ESP-IDF runs transactions this way (i2c_master_cmd_begin_static).

3. No 9 SCL clocks (SCL_RST_SLV) in resetMaster(). After them the GT911 did not ACK the first transaction after Configure. The PCF8563 was not affected. ESP-IDF does not clear the bus in i2c_param_config.

4. The last byte of a read in its own segment. Reads of 64 and 96 bytes timed out every time in the last segment (READ n-1, READLAST, STOP) and left the bus hung. 4, 32, 33, 63, 65, 128 and 184 bytes worked. Why only these lengths fail is not known. ESP-IDF reads the last byte separately (i2c_master_read). With that, all these lengths work.

5. Both FIFOs reset at the start of transmit(). Bytes left in the TX FIFO after a NACK went out in the following transactions. After a NACK on a data byte (made on purpose with ack_exp = 1), every following PCF8563 read failed and TXFIFO_CNT kept growing. With the reset, as ESP-IDF does (i2c_master_cmd_begin), the reads work again. The first read right after such a NACK still fails. A Go port of the ESP-IDF v4.4.8 driver gives the same result there.

Each change is a separate commit, so they can be reviewed one by one.

Test

One program using only machine.I2C0, run after full power cycles. The program enables the internal pull-ups after Configure. With this PR:

• GT911 read as the first transaction after Configure, and after 5 more Configure calls: "911".
• Read, write, and read without write to an absent address (0x42): expected ACK not NACK. With 0.42.0 the read returned nil.
• PCF8563 or GT911 read right after each of these: correct data, no Configure needed.
• 200 cycles of absent read, PCF8563 read, GT911 read: no failures. 1000 GT911 reads: no failures.
• Reads from the GT911 config area (0x8047) of 1, 2, 3, 31, 32, 33, 40 and 64 bytes: same data as one 64-byte read. 63, 64, 65, 96, 128 and 184 bytes, 3 times each: same data as a 184-byte read with a Go port of the ESP-IDF v4.4.8 driver.
• GT911 touch driver on machine.I2C0: touches before sleep, NACKs while asleep, touches after wake-up with no errors. With only change 1 applied there were no touches after wake-up.

Changes 2 and 3 were found by switching single parts of that ESP-IDF port to the TinyGo behaviour. Writing the whole transaction at once made transactions after an address NACK fail: all of them when the address and the data were one WRITE, one of them when the address was its own WRITE without END. The 9 SCL clocks made the GT911 NACK the first transaction. Timing values, drive strength, FSM_RST, the reset pulse on enable and SLAVE_SCL_STRETCH_EN made no difference in that test.

Tested only on ESP32-S3. The file is shared with ESP32-C3 and ESP32-C6. It builds for esp32c3-generic and xiao-esp32c6, but I have no hardware to test them. make test was not run.

[deadprogram]

Thanks for the careful work and the detailed test notes @0hJonny. The following is edited from an automated review:

1. transmit() returns right away on NACK or timeout, and the TX/RX FIFOs are only reset in startMaster(). If a device ACKs its address but NACKs a data byte in a longer write, the rest of that write stays in the TX FIFO and goes out at the start of the next transaction. ESP-IDF resets both FIFOs at the start of every transaction (https://github.com/espressif/esp-idf/blob/v4.4.8/components/driver/i2c.c#L1456). Perhaps do the same at the top of transmit()?

2. With the SCL_RST_SLV clocks gone from resetMaster(), there is no way left to recover a device that holds SDA low, for example after a reset in the middle of a read. ESP-IDF still clears the bus, just only on a timeout or a busy bus (i2c_hw_fsm_reset, https://github.com/espressif/esp-idf/blob/v4.4.8/components/driver/i2c.c#L617), and its software version ends with a STOP (https://github.com/espressif/esp-idf/blob/v4.4.8/components/driver/i2c.c#L579). Could the GT911 problem come from the missing STOP after the clocks, rather than the clocks themselves? A follow up that clears the bus on timeout might be worth it. Seems like a good idea maybe?

3. I tested this on a XIAO ESP32-C6 and a XIAO ESP32-C3, each with the Seeed XIAO expansion board (SSD1306 at 0x3C, PCF8563 at 0x51) at 400 kHz. On dev a read scan found every address, and after the first write NACK every transaction failed until the next Configure. With this PR the scan finds only 0x3C and 0x51, all absent device transactions return expected ACK not NACK, the RTC reads correctly right after each one, reads of 1 to 184 bytes all match, 200 cycles of absent read, RTC read and OLED write had no failures, and the display works. Both chips gave the same results.

What do you think?

[0hJonny]

Thank you for testing on the C3 and C6, that covers what I couldn't.

Both points make sense. I'll add a FIFO reset at the start of transmit() and test it, including a NACK on a data byte in a longer write followed by a read from another device. I'll also test your STOP idea on the GT911: the 9 SCL clocks followed by a STOP, then the first transaction after Configure. I'll post the results here.

[0hJonny]

Thanks for the review, @deadprogram. Here are the results for both points, plus one more finding.

FIFO reset. You were right. With a NACK on a data byte (a PCF8563 WRITE with ack_exp = 1), every following PCF8563 read failed and TXFIFO_CNT kept growing. With both FIFOs reset at the start of transmit(), the reads work again. Added as commit 7ce6172. The first read right after such a NACK still fails; a Go port of the ESP-IDF v4.4.8 driver does the same.

Bus clear. You were right about the STOP. I added the old 9 clocks after Configure on the PR code (3 runs after power off, 12 tries per variant):

• 9 clocks: GT911 NACKs the next read, 12/12. Configure again after the clocks does not help.
• 9 clocks + STOP made on the pins as GPIOs (as at the end of i2c_master_clear_bus): GT911 ACKs the next read, 12/12.
• Switching the pins to GPIO and back without the STOP: NACK, 12/12.
• 9 clocks + a STOP command on the controller: it did not complete, GT911 NACKs, 12/12.

I would keep this PR without the clocks and add a bus clear with a GPIO STOP in a follow-up PR with its own test. Does that work for you?

100 kHz. A read started right after an address NACK timed out 19/20 (BUS_BUSY still set); with a 20 us pause, 0/20. On dev the same read returns wrong data without an error at both speeds. ESP-IDF resets the controller when BUS_BUSY is set, so I would handle that in the follow-up too.

[deadprogram]

Thanks for testing all of those variants @0hJonny, that makes the bus clear question much clearer. The following is edited from an automated review:

1. Could the first read failing right after a data NACK be the same BUS_BUSY state you saw at 100 kHz? If so, the follow-up that resets the controller when BUS_BUSY is set might fix both.

2. Doing the bus clear with a GPIO STOP and the BUS_BUSY handling in a follow-up PR sounds good to me.

[0hJonny]

Thanks for merging, @deadprogram!

On point 1, I checked it (3 runs after power off, 30 cases per variant). At 400 kHz the next read fails also when BUS_BUSY is 0 before it: with a 20 us or 1 ms pause it still fails with a NACK (60/60), and the read after it works. The ESP-IDF port fails that first read too, without a reset. At 100 kHz the PR code fails both reads after the NACK, while the ESP-IDF port passes the first read in 27/30, each time after its reset on BUS_BUSY. So the BUS_BUSY reset looks right for 100 kHz, but not for this 400 kHz case.

One caveat: the NACK is made with ack_exp = 1, so the PCF8563 actually ACKs the byte. A device that really NACKs could behave differently. I'll look into it in the follow-up.

[deadprogram]

Apparently I should have run another hardware test before merge @0hJonny

Please see this failure on our hardware in the loop server: https://github.com/tinygo-org/tinygo/runs/109145110032

This is the test code itself: https://github.com/tinygo-org/tinyhci/blob/main/xiao-esp32c3/main.go

So looks like something needs to be done about this case sooner rather than later.

[0hJonny]

@deadprogram Sorry about that, I saw it too. I don't know yet which of the 5 commits causes it, and I don't have an MPU6050 here to reproduce it. Would it help if I open a draft PR that reverts the commits one at a time, so tinyhci shows which one breaks it? Or would you prefer to revert the whole PR first, and I'll send it again once it passes on tinyhci?

[deadprogram]

@deadprogram Sorry about that, I saw it too. I don't know yet which of the 5 commits causes it, and I don't have an MPU6050 here to reproduce it. Would it help if I open a draft PR that reverts the commits one at a time, so tinyhci shows which one breaks it? Or would you prefer to revert the whole PR first, and I'll send it again once it passes on tinyhci?

Let me bisect it real quick here... stand by...

[0hJonny]

@deadprogram Sorry about that, I saw it too. I don't know yet which of the 5 commits causes it, and I don't have an MPU6050 here to reproduce it. Would it help if I open a draft PR that reverts the commits one at a time, so tinyhci shows which one breaks it? Or would you prefer to revert the whole PR first, and I'll send it again once it passes on tinyhci?

Let me bisect it real quick here... stand by...

Thank you! Let me know which one it is, and I'll look into the fix.

[deadprogram]

@0hJonny I bisected it on a XIAO ESP32-C3 with the Seeed expansion board and an MPU-6050, running the i2cConnection() code from tinyhci. The following is edited from the results:

1. The first bad commit is ea7f352 (do not clock SCL when configuring I2C). 292609f and 8e06781 pass. From ea7f352 on, the first accel.Configure() after a chip reset fails with expected ACK not NACK. The next Configure and WHO_AM_I read then work (0x68).

2. dev with only ea7f352 reverted passes, first attempt included, in 2 runs.

3. The same writes and 1 byte reads to the PCF8563 on that board work with the current code, so this looks specific to the MPU-6050. It is the same pattern as the GT911 in reverse. The MPU-6050 wants the bus clear after a reset, the GT911 does not want it without the STOP.

Perhaps the bus clear with the GPIO STOP from your follow-up could go in now, since that made the GT911 happy too? Or we could put the 9 clocks back for now and do the full fix in the follow-up. What do you think?

[0hJonny]

@deadprogram Thank you for bisecting it! Since dev with ea7f352 reverted already passes, I think putting the 9 clocks back now is the safer quick fix. It only brings back the old GT911 behaviour (a NACK on the first transaction after Configure), and a driver can retry that. Then I'll do the bus clear with the GPIO STOP in the follow-up, test it with the GT911 and the PCF8563 here, and wait for tinyhci to pass before merging. Should I open the revert PR, or would you prefer to do it?

[deadprogram]

I will open the revert PR so that it can be run by the HCI.

[0hJonny]

Thanks! I'll start on the bus clear with the GPIO STOP for the follow-up.

[deadprogram]

actually I am making a run at the GPIO STOP myself right now, since I have the hardware setup. more shortly...

[0hJonny]

Great, thank you! I can test it on the GT911 on my ESP32-S3 board once you have a branch.

[deadprogram]

Please see #5783 and thanks!