espressif / esp-idf

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

New i2c master driver issue: read blocks forever (IDFGH-11957) #13035

Closed cpehonk closed 7 months ago

cpehonk commented 7 months ago

Answers checklist.

IDF version.

v5.2 master branch

Espressif SoC revision.

ESP32 Rev1.0

Operating System used.

Windows

How did you build your project?

Command line with Make

If you are using Windows, please specify command line type.

PowerShell

Development Kit.

WEMOS LOLIN32 (ESP32 WROVER)

Power Supply used.

USB

What is the expected behavior?

example: read chip revision of BME280 => i2c_master_transmit_receive should deliver chip revision byte

What is the actual behavior?

i2c_master_transmit_receive blocks forever, regardless if a timeout value != -1 is specified

Steps to reproduce.

esp_err_t i2c_master_bus_read_byte(i2c_master_dev_handle_t dev_handle, uint8_t mem_address, uint8_t data) { uint8_t buf[1] = {mem_address}; uint8_t buffer[1]; esp_err_t ret = i2c_master_transmit_receive(dev_handle, buf, 1, buffer, 1, CONFIG_I2C_TIMEOUT); data = buffer[0]; return ret; }

void app_main(void) { i2c_master_bus_config_t conf = { .i2c_port = -1, .sda_io_num = GPIO_NUM_23, .scl_io_num = GPIO_NUM_19, .clk_source = I2C_CLK_SRC_DEFAULT, .glitch_ignore_cnt = 7, };

ESP_LOGI(LOGTAG, "MasterInit call new master bus");
i2c_master_bus_handle_t handle = NULL;
esp_err_t err = i2c_new_master_bus(&conf, &handle);
if (err != ESP_OK)
{
    ESP_LOGE(LOGTAG, "i2c new master failed:%d", err);
}
else if (i2c_master_probe(handle, 0x76, 10) == ESP_OK)
{
    ESP_LOGI(LOGTAG, "found device at $%02x", 0x76);

    i2c_master_dev_handle_t hDev = NULL;
    i2c_device_config_t cfg = {
        .dev_addr_length = I2C_ADDR_BIT_LEN_7,
        .device_address = 0x76,
        .scl_speed_hz = 400000,
    };

    err = i2c_master_bus_add_device(handle, &cfg, &hDev);
    if (err == ESP_OK)
    {
        ESP_LOGI(LOGTAG, "read chip revision of BM*280");
        uint8_t reg = 208;
        uint8_t data = 0;

        err = i2c_master_bus_read_byte(hDev, reg, &data);
        ESP_LOGI(LOGTAG, "receive: %d", err);
        if (err == ESP_OK)
            ESP_LOGI(LOGTAG, "Chip ID=%02x", data);
        else
            ESP_LOGE(LOGTAG, "failed %d", err);
    }

    // freigeben
    i2c_master_bus_rm_device(hDev);
}

Debug Logs.

I (333) i2c_master.c: #cmds=2, addr=$76, wait=1
I (333) i2c_master.c: 1) status=4
I (343) i2c_master.c: 2) status=4
I (343) i2c_master.c: op code=0 (read=2)
I (343) i2c_master.c: start end command...
I (353) i2c_master.c: ... done.
I (353) i2c_master.c: #cmds=1, addr=$76, wait=1
I (363) i2c_master.c: 1) status=4
I (363) i2c_master.c: 2) status=4
I (373) i2c_master.c: op code=3 (read=2)
I (373) i2c_master.c: start end command...
I (383) i2c_master.c: ... done.
I (383) i2c_master.c: master trans start ...
I (383) i2c_master.c: ... done.
I (393) i2c_master.c: waiting for trans_done done.
I (393) main: found device at $76
I (403) main: read chip revision of BM*280
I (403) i2c_master.c: #cmds=6, addr=$76, wait=10
I (413) i2c_master.c: 1) status=4
I (413) i2c_master.c: 2) status=4
I (423) i2c_master.c: op code=0 (read=2)
I (423) i2c_master.c: start end command...
I (433) i2c_master.c: ... done.
I (433) i2c_master.c: #cmds=5, addr=$76, wait=10
I (433) i2c_master.c: 1) status=4
I (443) i2c_master.c: 2) status=4
I (443) i2c_master.c: op code=1 (read=2)
I (453) i2c_master.c: write...
I (453) i2c_master.c: ... done.
I (453) i2c_master.c: #cmds=4, addr=$76, wait=10
I (463) i2c_master.c: 1) status=1
I (463) i2c_master.c: 2) status=1
I (473) i2c_master.c: op code=0 (read=2)
I (473) i2c_master.c: start end command...
I (483) i2c_master.c: ... done.
I (483) i2c_master.c: #cmds=3, addr=$76, wait=10
I (493) i2c_master.c: 1) status=1
I (493) i2c_master.c: 2) status=1
I (493) i2c_master.c: op code=2 (read=2)
I (503) i2c_master.c: read...
I (503) i2c_master.c: ... done.
I (513) i2c_master.c: #cmds=2, addr=$76, wait=10
I (513) i2c_master.c: 1) status=0
I (523) i2c_master.c: 2) status=0
I (523) i2c_master.c: op code=2 (read=2)
I (523) i2c_master.c: read...
I (533) i2c_master.c: ... done.
I (533) i2c_master.c: #cmds=1, addr=$76, wait=10
I (543) i2c_master.c: 1) status=0
I (543) i2c_master.c: 2) status=0
I (543) i2c_master.c: op code=3 (read=2)
I (553) i2c_master.c: start end command...
I (553) i2c_master.c: ... done.
I (563) i2c_master.c: master trans start ...

More Information.

I traced it down to function s_i2c_send_commands (i2c_master.c #423). i2c_hal_master_trans_start(hal); never returns...

mythbuster5 commented 7 months ago

Yes, I already notice this. And it has been fixed internally. I think it will sync to github very quickly.

mythbuster5 commented 7 months ago

A quicker way if you want to try is to find s_i2c_read_command function. Copy-paste following code.

static bool s_i2c_read_command(i2c_master_bus_handle_t i2c_master, i2c_operation_t *i2c_operation, uint8_t *fifo_fill, BaseType_t *do_yield)
{
    i2c_master->async_break = false;
    const size_t remaining_bytes = i2c_operation->total_bytes - i2c_operation->bytes_used;
    const i2c_ll_hw_cmd_t hw_end_cmd = {
        .op_code = I2C_LL_CMD_END
    };
    i2c_hal_context_t *hal = &i2c_master->base->hal;
    i2c_bus_handle_t handle = i2c_master->base;
    i2c_ll_hw_cmd_t hw_cmd = i2c_operation->hw_cmd;

    *fifo_fill = MIN(remaining_bytes, SOC_I2C_FIFO_LEN - i2c_master->read_len_static);
    i2c_master->rx_cnt = *fifo_fill;
    hw_cmd.byte_num = *fifo_fill;

    i2c_master->contains_read = true;
#if !SOC_I2C_STOP_INDEPENDENT
    if (remaining_bytes < SOC_I2C_FIFO_LEN - 1) {
        if (i2c_operation->hw_cmd.ack_val == ACK_VAL) {
            if (remaining_bytes != 0) {
                i2c_ll_master_write_cmd_reg(hal->dev, hw_cmd, i2c_master->cmd_idx);
                i2c_master->read_len_static = i2c_master->rx_cnt;
                i2c_master->cmd_idx++;
            }
            i2c_master->read_buf_pos = i2c_master->trans_idx;
        } else {
            i2c_ll_master_write_cmd_reg(hal->dev, hw_cmd, i2c_master->cmd_idx);
            i2c_master->cmd_idx++;
        }
        i2c_master->trans_idx++;
        i2c_master->i2c_trans.cmd_count--;
        if (i2c_master->async_trans == false) {
            if (xPortInIsrContext()) {
                xSemaphoreGiveFromISR(i2c_master->cmd_semphr, do_yield);
            } else {
                xSemaphoreGive(i2c_master->cmd_semphr);
            }
        }
    } else {
        atomic_store(&i2c_master->status, I2C_STATUS_READ);
        portENTER_CRITICAL_SAFE(&handle->spinlock);
        i2c_ll_master_write_cmd_reg(hal->dev, hw_cmd, i2c_master->cmd_idx);
        i2c_ll_master_write_cmd_reg(hal->dev, hw_end_cmd, i2c_master->cmd_idx + 1);
        if (i2c_master->async_trans == false) {
            i2c_hal_master_trans_start(hal);
        } else {
            i2c_master->async_break = true;
        }
        portEXIT_CRITICAL_SAFE(&handle->spinlock);
    }
#else
    portENTER_CRITICAL_SAFE(&handle->spinlock);
    // If the read command work with ack_val, but no bytes to read, we skip
    // this command, and run next command directly.
    if (hw_cmd.ack_val == ACK_VAL) {
        if (i2c_operation->total_bytes == 0) {
            i2c_master->trans_idx++;
            hw_cmd = i2c_master->i2c_trans.ops[i2c_master->trans_idx].hw_cmd;
            i2c_master->i2c_trans.cmd_count--;
        }
    }
    i2c_ll_master_write_cmd_reg(hal->dev, hw_cmd, i2c_master->cmd_idx);
    i2c_ll_master_write_cmd_reg(hal->dev, hw_end_cmd, i2c_master->cmd_idx + 1);
    portEXIT_CRITICAL_SAFE(&handle->spinlock);
    i2c_master->status = I2C_STATUS_READ;
    portENTER_CRITICAL_SAFE(&handle->spinlock);
    if (i2c_master->async_trans == false) {
        i2c_hal_master_trans_start(hal);
    } else {
        i2c_master->async_break = true;
    }
    portEXIT_CRITICAL_SAFE(&handle->spinlock);
#endif

    return i2c_master->async_break;
}
cpehonk commented 7 months ago

Thx, that does the job! :)