espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
13.47k stars 7.25k forks source link

Allow I2C to send empty commands (IDFGH-11887) #12973

Open 5p4k opened 8 months ago

5p4k commented 8 months ago

Answers checklist.

General issue report

i2c_master_transmit explicitly forbids sending 0-length buffers. However, there is in principle nothing wrong with doing so, and it was possible with the legacy driver.

In fact, we relied on this to wake up a PN532 controller (a popular NFC reader module by NXP), since the chip wakes up when it detects its address on I2C, but takes some time before being ready to receive the command body (https://www.nxp.com/docs/en/user-guide/141520.pdf, page 57, paragraph named "variant").

I tried disable the check line below and transmit an empty buffer, and everything worked fine, producing an I2C write packet with no data.

https://github.com/espressif/esp-idf/blob/b3f7e2c8a4d354df8ef8558ea7caddc07283a57b/components/esp_driver_i2c/i2c_master.c#L950

So I wonder wethere there is any reason to forbid an empty buffer, and wheter this behavior could be restored?

mythbuster5 commented 8 months ago

If you know when to wake up the sensor, you can use i2c_master_probe(i2c_master_bus_handle_t bus_handle, uint16_t address, int xfer_timeout_ms) instead. It will only address and no buffer.

5p4k commented 8 months ago

You are right, in fact that was my first attempt, but I did not manage to make that work. So I've looked a bit further into i2c_master_probe, and I cannot get it to produce any signal on the line. I'm not sure if it's a duplicate of https://github.com/espressif/esp-idf/issues/12159 ; here is what I have been trying:

#include <cstdint>
#include <array>
#include <esp_log.h>
#include <driver/i2c_master.h>

namespace pinout {
    constexpr gpio_num_t i2c_scl = GPIO_NUM_17;
    constexpr gpio_num_t i2c_sda = GPIO_NUM_18;

    constexpr std::uint16_t dev_addr = 0x24;

    constexpr i2c_device_config_t dev_config{
            .dev_addr_length = I2C_ADDR_BIT_LEN_7,
            .device_address = pinout::dev_addr,
            .scl_speed_hz = 400'000};

    constexpr i2c_master_bus_config_t bus_config = {
            .i2c_port = -1 /* autoselect */,
            .sda_io_num = pinout::i2c_sda,
            .scl_io_num = pinout::i2c_scl,
            .clk_source = I2C_CLK_SRC_DEFAULT,
            .glitch_ignore_cnt = 7 /* typical */,
            .intr_priority = 0 /* default */,
            .trans_queue_depth = 10,
            .flags = {.enable_internal_pullup = true}};
}

void attempt_probe(i2c_master_bus_handle_t bus, std::uint16_t dev_addr) {
    const auto r = i2c_master_probe(bus, dev_addr, 500);
    if (r == ESP_OK) {
        ESP_LOGI("PROBE", "Successful probe at 0x%x", dev_addr);
    } else {
        ESP_LOGE("PROBE", "Failed probe at 0x%x: %s", dev_addr, esp_err_to_name(r));
    }
}

extern "C" int app_main() {
    i2c_master_bus_handle_t bus_handle = nullptr;
    i2c_master_dev_handle_t dev_handle = nullptr;

    ESP_ERROR_CHECK(i2c_new_master_bus(&pinout::bus_config, &bus_handle));
    ESP_ERROR_CHECK(i2c_master_bus_add_device(bus_handle, &pinout::dev_config, &dev_handle));

    ESP_LOGI("PROBE", "Attempting probe.");

    attempt_probe(bus_handle, pinout::dev_addr << 1);
    attempt_probe(bus_handle, (pinout::dev_addr << 1) | 1);
    attempt_probe(bus_handle, pinout::dev_addr);

    ESP_LOGI("PROBE", "Sending a command to see if anything changes.");

    std::array<std::uint8_t, 5> dummy = {0x10, 0x20, 0x30, 0x40, 0x50};
    ESP_ERROR_CHECK(i2c_master_transmit(dev_handle, dummy.data(), dummy.size(), 500));

    ESP_LOGI("PROBE", "Reattempting probe.");

    attempt_probe(bus_handle, pinout::dev_addr << 1);
    attempt_probe(bus_handle, (pinout::dev_addr << 1) | 1);
    attempt_probe(bus_handle, pinout::dev_addr);

    return 0;
}

I tested with a logic analyzer but the only signal I get is from the i2c_master_transmit call. I was not sure whether I should have been using the 7 bit device address or not, so I tried all combinations. Other things I tried:

No matter what, the only signal produced is the i2c_master_transmit (there is nothing else in this recording even though it certainly was started before the probes and ended after returning):

no probing on line

The i2c_master_probe command, however, is always successful: i2c_master_probe successful

Those DEBUG messages come from the following modifications to s_i2c_send_commands:

diff --git a/components/esp_driver_i2c/i2c_master.c b/components/esp_driver_i2c/i2c_master.c
index 91e44952d5..c3dbb51871 100644
--- a/components/esp_driver_i2c/i2c_master.c
+++ b/components/esp_driver_i2c/i2c_master.c
@@ -390,2 +390,3 @@ static void s_i2c_send_commands(i2c_master_bus_handle_t i2c_master, TickType_t t
             i2c_master->trans_idx = 0;
+            ESP_LOGW("DEBUG", "Exiting because I cannot take semaphore");
             return;
@@ -398,2 +399,3 @@ static void s_i2c_send_commands(i2c_master_bus_handle_t i2c_master, TickType_t t
             xSemaphoreGive(i2c_master->cmd_semphr);
+            ESP_LOGW("DEBUG", "Exiting because timeout");
             return;
@@ -402,2 +404,3 @@ static void s_i2c_send_commands(i2c_master_bus_handle_t i2c_master, TickType_t t
         if (i2c_master->status == I2C_STATUS_ACK_ERROR) {
+            ESP_LOGW("DEBUG", "Exiting because ack error");
             const i2c_ll_hw_cmd_t hw_stop_cmd = {
@@ -413,6 +416,9 @@ static void s_i2c_send_commands(i2c_master_bus_handle_t i2c_master, TickType_t t
         if (i2c_operation->hw_cmd.op_code == I2C_LL_CMD_WRITE) {
+            ESP_LOGW("DEBUG", "Writing command");
             s_i2c_write_command(i2c_master, i2c_operation, &fifo_fill, &address_fill, NULL);
         } else if (i2c_operation->hw_cmd.op_code == I2C_LL_CMD_READ) {
+            ESP_LOGW("DEBUG", "Reading command");
             s_i2c_read_command(i2c_master, i2c_operation, &fifo_fill, NULL);
         } else {
+            ESP_LOGW("DEBUG", "Ending command");
             s_i2c_start_end_command(i2c_master, i2c_operation, &address_fill, NULL);

I'm not entirely sure what this means, but I would expect i2c_master_probe to always call s_i2c_start_end_command, not at the first call only; either way, s_i2c_start_end_command does not produce any switch in the line (although I'm not entirely sure whether that depends on my configuration?).

I'm on an ESP32S3, and esp-idf is on b3f7e2c8a4d354df8ef8558ea7caddc07283a57b.

ogimenezb commented 3 months ago

@5p4k have you been able to make PN532 work with new I2C implementation? have been trying for a week, even tried 5.3-beta2. I'm about to go back to old implementation.

Update: Just manage to get firmware after rebooting several times. If I reboot again it panics a few times.

I (31) boot: ESP-IDF v5.3-beta2 2nd stage bootloader
I (31) boot: compile time Jul  1 2024 21:03:59
I (31) boot: Multicore bootloader
I (36) boot: chip revision: v1.1
I (39) boot.esp32: SPI Speed      : 40MHz
I (44) boot.esp32: SPI Mode       : DIO
I (49) boot.esp32: SPI Flash Size : 2MB
I (53) boot: Enabling RNG early entropy source...
I (58) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (69) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (77) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (84) boot:  2 factory          factory app      00 00 00010000 00100000
I (92) boot: End of partition table
I (96) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=0bc8ch ( 48268) map
I (121) esp_image: segment 1: paddr=0001bcb4 vaddr=3ffb0000 size=02360h (  9056) load
I (125) esp_image: segment 2: paddr=0001e01c vaddr=40080000 size=01ffch (  8188) load
I (130) esp_image: segment 3: paddr=00020020 vaddr=400d0020 size=1e434h (123956) map
I (178) esp_image: segment 4: paddr=0003e45c vaddr=40081ffc size=0b3a8h ( 45992) load
I (203) boot: Loaded app from partition at offset 0x10000
I (203) boot: Disabling RNG early entropy source...
I (214) cpu_start: Multicore app
I (223) cpu_start: Pro cpu start user code
I (223) cpu_start: cpu freq: 160000000 Hz
I (223) app_init: Application information:
I (226) app_init: Project name:     esp-terminal
I (231) app_init: App version:      1
I (236) app_init: Compile time:     Jul  1 2024 21:20:12
I (242) app_init: ELF file SHA256:  d920fd0d3...
I (247) app_init: ESP-IDF:          v5.3-beta2
I (252) efuse_init: Min chip rev:     v0.0
I (257) efuse_init: Max chip rev:     v3.99 
I (262) efuse_init: Chip rev:         v1.1
I (267) heap_init: Initializing. RAM available for dynamic allocation:
I (274) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (280) heap_init: At 3FFB2CC0 len 0002D340 (180 KiB): DRAM
I (286) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (292) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (299) heap_init: At 4008D3A4 len 00012C5C (75 KiB): IRAM
I (307) spi_flash: detected chip: gd
I (309) spi_flash: flash io: dio
W (313) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (327) main_task: Started on CPU0
I (337) main_task: Calling app_main()
I (337) main: PN532 I2C initialization
D (337) i2c.common: new bus(0) at 0x3ffb615c
I (337) gpio: GPIO[22]| InputEn: 1| OutputEn: 1| OpenDrain: 1| Pullup: 1| Pulldown: 0| Intr:0 
I (347) gpio: GPIO[21]| InputEn: 1| OutputEn: 1| OpenDrain: 1| Pullup: 1| Pulldown: 0| Intr:0 
D (357) i2c.common: bus clock source frequency: 80000000hz
W (367) PN532: Sending :
W (367) PN532: 00 00 ff 02 fe d4 02 2a 00 
W (367) PN532: i2c_dev
I (377) gpio: GPIO[22]| InputEn: 1| OutputEn: 1| OpenDrain: 1| Pullup: 1| Pulldown: 0| Intr:0 
I (387) gpio: GPIO[21]| InputEn: 1| OutputEn: 1| OpenDrain: 1| Pullup: 1| Pulldown: 0| Intr:0 
E (397) i2c.master: I2C hardware timeout detected
E (397) i2c.master: s_i2c_synchronous_transaction(870): I2C transaction failed
I (407) gpio: GPIO[22]| InputEn: 1| OutputEn: 1| OpenDrain: 1| Pullup: 1| Pulldown: 0| Intr:0 
I (417) gpio: GPIO[21]| InputEn: 1| OutputEn: 1| OpenDrain: 1| Pullup: 1| Pulldown: 0| Intr:0 
E (427) i2c.master: i2c_master_transmit(1072): I2C transaction failed
ESP_ERROR_CHECK failed: esp_err_t 0x103 (ESP_ERR_INVALID_STATE) at 0x400d6afc
0x400d6afc: writecommand at C:/daemez.io/x/esp-terminal/components/daemez__esp_pn532/esp_pn532.c:1798 (discriminator 1)

file: "./components/daemez__esp_pn532/esp_pn532.c" line 1798
func: writecommand
expression: i2c_master_transmit(i2c_dev, packet, sizeof(packet), -1)

abort() was called at PC 0x4008631f on core 0
0x4008631f: _esp_error_check_failed at C:/Users/OscarGimenez/esp/v5.3-beta2/esp-idf/components/esp_system/esp_err.c:49

Backtrace: 0x40081872:0x3ffb4e50 0x40086329:0x3ffb4e70 0x4008bc7d:0x3ffb4e90 0x4008631f:0x3ffb4f00 0x400d6afc:0x3ffb4f30 0x400d6b32:0x3ffb4f60 0x400d6bb2:0x3ffb4f80 0x400d6680:0x3ffb4fa0 0x400ed99c:0x3ffb4fc0 0x40086e19:0x3ffb4ff0        
0x40081872: panic_abort at C:/Users/OscarGimenez/esp/v5.3-beta2/esp-idf/components/esp_system/panic.c:463
0x40086329: esp_system_abort at C:/Users/OscarGimenez/esp/v5.3-beta2/esp-idf/components/esp_system/port/esp_system_chip.c:92
0x4008bc7d: abort at C:/Users/OscarGimenez/esp/v5.3-beta2/esp-idf/components/newlib/abort.c:38
0x4008631f: _esp_error_check_failed at C:/Users/OscarGimenez/esp/v5.3-beta2/esp-idf/components/esp_system/esp_err.c:49
0x400d6afc: writecommand at C:/daemez.io/x/esp-terminal/components/daemez__esp_pn532/esp_pn532.c:1798 (discriminator 1)
0x400d6b32: sendCommandCheckAck at C:/daemez.io/x/esp-terminal/components/daemez__esp_pn532/esp_pn532.c:352
0x400d6bb2: getFirmwareVersion at C:/daemez.io/x/esp-terminal/components/daemez__esp_pn532/esp_pn532.c:303
0x400d6680: app_main at C:/daemez.io/x/esp-terminal/main/main.c:165
0x400ed99c: main_task at C:/Users/OscarGimenez/esp/v5.3-beta2/esp-idf/components/freertos/app_startup.c:208
0x40086e19: vPortTaskWrapper at C:/Users/OscarGimenez/esp/v5.3-beta2/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:134

ELF file SHA256: d920fd0d3

Rebooting...
ets Jun  8 2016 00:22:57

rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:7176
load:0x40078000,len:15564
ho 0 tail 12 room 4
load:0x40080400,len:4
0x40080400: _init at ??:?

load:0x40080404,len:3904
entry 0x40080640
I (31) boot: ESP-IDF v5.3-beta2 2nd stage bootloader
I (31) boot: compile time Jul  1 2024 21:03:59
I (31) boot: Multicore bootloader
I (36) boot: chip revision: v1.1
I (39) boot.esp32: SPI Speed      : 40MHz
I (44) boot.esp32: SPI Mode       : DIO
I (49) boot.esp32: SPI Flash Size : 2MB
I (53) boot: Enabling RNG early entropy source...
I (58) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (69) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (77) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (84) boot:  2 factory          factory app      00 00 00010000 00100000
I (92) boot: End of partition table
I (96) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=0bc8ch ( 48268) map
I (121) esp_image: segment 1: paddr=0001bcb4 vaddr=3ffb0000 size=02360h (  9056) load
I (125) esp_image: segment 2: paddr=0001e01c vaddr=40080000 size=01ffch (  8188) load
I (130) esp_image: segment 3: paddr=00020020 vaddr=400d0020 size=1e434h (123956) map
I (178) esp_image: segment 4: paddr=0003e45c vaddr=40081ffc size=0b3a8h ( 45992) load
I (203) boot: Loaded app from partition at offset 0x10000
I (203) boot: Disabling RNG early entropy source...
I (214) cpu_start: Multicore app
I (223) cpu_start: Pro cpu start user code
I (223) cpu_start: cpu freq: 160000000 Hz
I (223) app_init: Application information:
I (226) app_init: Project name:     esp-terminal
I (231) app_init: App version:      1
I (236) app_init: Compile time:     Jul  1 2024 21:20:12
I (242) app_init: ELF file SHA256:  d920fd0d3...
I (247) app_init: ESP-IDF:          v5.3-beta2
I (252) efuse_init: Min chip rev:     v0.0
I (257) efuse_init: Max chip rev:     v3.99 
I (262) efuse_init: Chip rev:         v1.1
I (267) heap_init: Initializing. RAM available for dynamic allocation:
I (274) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (280) heap_init: At 3FFB2CC0 len 0002D340 (180 KiB): DRAM
I (286) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (292) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (299) heap_init: At 4008D3A4 len 00012C5C (75 KiB): IRAM
I (307) spi_flash: detected chip: gd
I (309) spi_flash: flash io: dio
W (313) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (327) main_task: Started on CPU0
I (337) main_task: Calling app_main()
I (337) main: PN532 I2C initialization
D (337) i2c.common: new bus(0) at 0x3ffb615c
I (337) gpio: GPIO[22]| InputEn: 1| OutputEn: 1| OpenDrain: 1| Pullup: 1| Pulldown: 0| Intr:0 
I (347) gpio: GPIO[21]| InputEn: 1| OutputEn: 1| OpenDrain: 1| Pullup: 1| Pulldown: 0| Intr:0 
D (357) i2c.common: bus clock source frequency: 80000000hz
W (367) PN532: Sending :
W (367) PN532: 00 00 ff 02 fe d4 02 2a 00
W (367) PN532: i2c_dev
W (377) PN532: i2c_dev done
W (387) PN532: isready
W (387) PN532: isready done
W (387) PN532: Reading:
W (387) PN532: 00 00 ff 00 ff 00
W (407) PN532: isready
W (407) PN532: isready done
W (407) PN532: Reading:
W (407) PN532: 00 00 ff 06 fa d5 03 32 01 06 07 e8 00
I (407) main: PN532 Firmware version: 838927879
I (417) main_task: Returned from app_main()