esp32: i2c_read() error was returned successfully at the bus nack

[huarunlin]

Describe the bug
I use i2c_read() to read slave data. After sending the slave address on the bus, if the slave does not reply to ack, i2c_read() error returns the read success.

To Reproduce
esp32.overlay

&i2c0 {
	status = "okay";
	clock-frequency = <I2C_BITRATE_STANDARD>;
	sda-pin = <26>;
	scl-pin = <27>;
};

main.c

#include <errno.h>
#include <zephyr.h>
#include <sys/printk.h>
#include <device.h>
#include <drivers/i2c.h>

void main(void)
{
	const struct device *i2c_dev = DEVICE_DT_GET(DT_NODELABEL(i2c0));
	uint8_t buf[2];
	int i, ret;

	if (!device_is_ready(i2c_dev)) {
		printk("I2C: Device is not ready.\n");
		return;
	}

	while (1) {
		ret = i2c_read(i2c_dev, buf, 2, 0x30);
		if (0 == ret) {
			printk("i2c read success: 0x%02X%02X\n", buf[0], buf[1]);
		} else {
			printk("i2c read failure %d\n", ret);
		}
		k_msleep( 2000 );
	}
}

Steps to reproduce the behavior:

1. west build
2. west flash

Logs and console output

ets Jul 29 2019 12:21:46

rst:0x1 (POWERON_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:7088
load:0x40078000,len:14312
load:0x40080400,len:3688
entry 0x40080678
I (27) boot: ESP-IDF release/v4.3-120-gbcd7565ff 2nd stage bootloader
I (27) boot: compile time 12:15:10
I (28) boot: chip revision: 3
I (32) boot_comm: chip revision: 3, min. bootloader chip revision: 0
I (39) boot.esp32: SPI Speed      : 40MHz
I (44) boot.esp32: SPI Mode       : DIO
I (48) boot.esp32: SPI Flash Size : 16MB
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) boot_comm: chip revision: 3, min. application chip revision: 0
I (103) esp_image: segment 0: paddr=00010020 vaddr=00000020 size=0001ch (    28) 
I (111) esp_image: segment 1: paddr=00010044 vaddr=3ffb0000 size=0074ch (  1868) load
I (120) esp_image: segment 2: paddr=00010798 vaddr=3ffb074c size=002a0h (   672) load
I (128) esp_image: segment 3: paddr=00010a40 vaddr=40080000 size=042d8h ( 17112) load
I (144) esp_image: segment 4: paddr=00014d20 vaddr=00000000 size=0b318h ( 45848) 
I (162) esp_image: segment 5: paddr=00020040 vaddr=3f400040 size=011ach (  4524) map
I (164) esp_image: segment 6: paddr=000211f4 vaddr=00000000 size=0ee24h ( 60964) 
I (190) esp_image: segment 7: paddr=00030020 vaddr=400d0020 size=03e38h ( 15928) map
I (199) boot: Loaded app from partition at offset 0x10000
I (199) boot: Disabling RNG early entropy source...
*** Booting Zephyr OS build zephyr-v3.0.0  ***
[00:00:00.428,000] <dbg> esp32_intc:i2c read success: 0xEFEF
 esp_intr_alloc_intrstatus: Connected src 22 to int 2 (cpu 0)
[00:00:00.428,000] <dbg> esp32_intc: esp_intr_alloc_intrstatus: Connected src 49 to int 3 (cpu 0)
i2c read success: 0xEFEF
i2c read success: 0xEFEF
i2c read success: 0xEFEF
i2c read success: 0xEFEF
i2c read success: 0xEFEF
i2c read success: 0xEFEF
i2c read success: 0xEFEF
i2c read success: 0xEFEF
i2c read success: 0xEFEF
i2c read success: 0xEFEF

Environment (please complete the following information):

• OS: Windows
• Commit: 4f8d78c

Additional context
I guess it is because the ACK ERR interrupt is not used in the i2c_read() processing, and the esp32 cannot generate the ACK ERR flag without enabling the ACK ERR interrupt. So I modified i2c_esp32.c, i2c_read() can return error correctly.

i2c_esp32.c

static int IRAM_ATTR i2c_esp32_read_msg(const struct device *dev,
	struct i2c_msg *msg, uint16_t addr)
{
	struct i2c_esp32_data *data = (struct i2c_esp32_data *const)(dev)->data;
	uint8_t rd_filled = 0;
	bool check_ack = false;
	uint8_t *read_pr = NULL;
	int ret = 0;

	/* reset command index and set status as read operation */
	data->cmd_idx = 0;
	data->status = I2C_STATUS_READ;

	i2c_hw_cmd_t cmd = {
		.op_code = I2C_LL_CMD_READ
	};

	i2c_hw_cmd_t hw_end_cmd = {
		.op_code = I2C_LL_CMD_END,
	};

	/* Set the R/W bit to R */
	addr |= BIT(0);

	if (msg->flags & I2C_MSG_RESTART) {
		/* write restart command and address */
		i2c_esp32_write_addr(dev, addr);
		check_ack = true;  // need send addr
	}

	while (msg->len) {
		rd_filled = (msg->len > SOC_I2C_FIFO_LEN) ? SOC_I2C_FIFO_LEN : (msg->len - 1);
		read_pr = msg->buf;
		msg->len -= rd_filled;

		if (rd_filled) {
			cmd = (i2c_hw_cmd_t) {
				.op_code = I2C_LL_CMD_READ,
				.ack_en = false,
				.ack_val = 0,
				.byte_num = rd_filled
			};

			i2c_hal_write_cmd_reg(&data->hal, cmd, data->cmd_idx++);
		}

		/* I2C master won't acknowledge the last byte read from the
		 * slave device. Divide the read command in two segments as
		 * recommended by the ESP32 Technical Reference Manual.
		 */
		if (msg->len == 1) {
			cmd = (i2c_hw_cmd_t)  {
				.op_code = I2C_LL_CMD_READ,
				.byte_num = 1,
				.ack_val = 1,
			};
			msg->len = 0;
			rd_filled++;
			i2c_hal_write_cmd_reg(&data->hal, cmd, data->cmd_idx++);
		}

		if (msg->len == 0) {
			cmd = (i2c_hw_cmd_t)  {
				.op_code = I2C_LL_CMD_STOP,
				.byte_num = 0,
				.ack_val = 0,
				.ack_en = 0
			};
			i2c_hal_write_cmd_reg(&data->hal, cmd, data->cmd_idx++);
		}

		i2c_hal_write_cmd_reg(&data->hal, hw_end_cmd, data->cmd_idx++);
		if (check_ack) {
                       /* When the address needs to be sent, enable the tx related interrupt */
			data->status = I2C_STATUS_WRITE;
			i2c_hal_enable_master_tx_it(&data->hal);
			check_ack = false;
		} else {
			data->status = I2C_STATUS_READ;
			i2c_hal_enable_master_rx_it(&data->hal);
		}

		ret = i2c_esp32_transmit(dev);
		if (ret < 0) {
			LOG_ERR("I2C transfer error: %d", ret);
			return ret;
		}

		i2c_hal_read_rxfifo(&data->hal, msg->buf, rd_filled);
		msg->buf += rd_filled;

		/* reset fifo read pointer */
		data->cmd_idx = 0;
	}

	return 0;
}

[steveatinfincia]

Hello :)

I'm working on a couple new I2C drivers for Zephyr (Sensirion SCD4X/SEN5X, X-Powers AXP192 PMIC, and a few others found on M5Stack ESP32 boards), and by chance I ended up rebasing my local tree right after the above commit (092406b) was merged.

I'm seeing some odd behavior now with ESP32 i2c peripheral, specifically rx buffers that contain invalid responses from i2c devices, which is noticeable because Sensirion includes a CRC covering the sensor data in the I2C response itself.

With that commit applied, I started seeing CRC failures not only with my new drivers but with drivers that are already in the Zephyr tree. When I revert it everything works.

I wiped out my zephyr tree and reinstalled the toolchain to avoid any local quirks, branched off from main again without any of my new code included, and ran some of the samples.

Here's samples/sensor/sgp40_sht4x:

*** Booting Zephyr OS build v3.1.0-rc3-6-g4ae24f90496b  ***
Failed to fetch sample from SHT4X device
[00:00:00.709,000] <err> SHT4X: Invalid CRC for T.
[00:00:00.709,000] <err> SHT4X: Failed to fetch data.

Same sample with 092406b reverted:

*** Booting Zephyr OS build v3.1.0-rc3-5-gd5782ba4fb3a  ***
SHT4X: 28.36 Temp. [C] ; 44.21 RH [%]
SHT4X: 28.38 Temp. [C] ; 44.22 RH [%]
SHT4X: 28.38 Temp. [C] ; 44.35 RH [%]

[LucasTambor]

@steveatinfincia Thanks for reporting this issue. PR #46174 should resolve your problem.

[vshymanskyy]

@huarunlin did you have any luck with your AXP192 driver?

[a-jayb]

Hello :)

I'm working on a couple new I2C drivers for Zephyr (Sensirion SCD4X/SEN5X, X-Powers AXP192 PMIC, and a few others found on M5Stack ESP32 boards), and by chance I ended up rebasing my local tree right after the above commit (092406b) was merged.

I'm seeing some odd behavior now with ESP32 i2c peripheral, specifically rx buffers that contain invalid responses from i2c devices, which is noticeable because Sensirion includes a CRC covering the sensor data in the I2C response itself.

With that commit applied, I started seeing CRC failures not only with my new drivers but with drivers that are already in the Zephyr tree. When I revert it everything works.

I wiped out my zephyr tree and reinstalled the toolchain to avoid any local quirks, branched off from main again without any of my new code included, and ran some of the samples.

Here's samples/sensor/sgp40_sht4x:

*** Booting Zephyr OS build v3.1.0-rc3-6-g4ae24f90496b  ***
Failed to fetch sample from SHT4X device
[00:00:00.709,000] <err> SHT4X: Invalid CRC for T.
[00:00:00.709,000] <err> SHT4X: Failed to fetch data.

Same sample with 092406b reverted:

*** Booting Zephyr OS build v3.1.0-rc3-5-gd5782ba4fb3a  ***
SHT4X: 28.36 Temp. [C] ; 44.21 RH [%]
SHT4X: 28.38 Temp. [C] ; 44.22 RH [%]
SHT4X: 28.38 Temp. [C] ; 44.35 RH [%]

Hi. Were you able to finish developing an I2C drivers for both the SCD4x and SEN5x sensors?