mcp23017: failed test_app, I2C software timeout (AEGHB-1197)

[stkw0]

Answers checklist.

• I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
• I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
• I have searched the issue tracker for a similar issue and not found a similar issue.

IDF version.

v5.5.0

Espressif SoC revision.

ESP32-P4

Operating System used.

Linux

How did you build your project?

Command line with idf.py

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

None

Development Kit.

Olimex esp32-p4-devkit

Power Supply used.

USB

What is the expected behavior?

Test program pass without errors

What is the actual behavior?

MCP23017 TEST
Running Device mcp23017 test, connect A-B port together...
I (88) i2c_bus: i2c0 bus inited
I (88) i2c_bus: I2C Bus V2 Config Succeed, Version: 1.1.0
E (289) i2c.master: I2C software timeout
E (289) i2c.master: s_i2c_synchronous_transaction(980): I2C transaction failed
E (289) i2c.master: i2c_master_transmit_receive(1283): I2C transaction failed
E (489) i2c.master: s_i2c_synchronous_transaction(980): I2C transaction failed
E (489) i2c.master: i2c_master_multi_buffer_transmit(1249): I2C transaction failed
E (689) i2c.master: I2C software timeout
E (689) i2c.master: s_i2c_synchronous_transaction(980): I2C transaction failed
E (689) i2c.master: i2c_master_transmit_receive(1283): I2C transaction failed
E (889) i2c.master: s_i2c_synchronous_transaction(980): I2C transaction failed
E (889) i2c.master: i2c_master_multi_buffer_transmit(1249): I2C transaction failed
./main/mcp23017_test.c:41:Device mcp23017 test, connect A-B port together:FAIL:Function [mcp23017][iot][device].  Expression Evaluated To FALSEMALLOC_CAP_8BIT: Before 602688 bytes free, After 601220 bytes free (delta -1468)

I (890) main_task: Returned from app_main()

Steps to reproduce.

1. Create a project using the test_app found in the mcp23017 component
2. Set I2C_MASTER_SCL_IO and I2C_MASTER_SDA_IO according to the board (in the Olimex devkit board it's GPIO_NUM_8 and GPIO_NUM_7 respectively)=
3. Change unity_run_menu to unity_run_all_tests
4. idf -p /dev/ttyACM0 flash monitor

Debug Logs.

Full run output:

--- esp-idf-monitor 1.7.0 on /dev/ttyACM0 115200
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H
ESP-ROM:esp32p4-eco2-20240710
Build:Jul 10 2024
rst:0x17 (CHIP_USB_UART_RESET),boot:0xf (SPI_FAST_FLASH_BOOT)
Core0 Saved PC:0x4ff038fa
--- 0x4ff038fa: esp_cpu_wait_for_intr at /usr/share/esp-idf/components/esp_hw_support/cpu.c:57
Core1 Saved PC:0x4ff038fa
--- 0x4ff038fa: esp_cpu_wait_for_intr at /usr/share/esp-idf/components/esp_hw_support/cpu.c:57
SPI mode:DIO, clock div:1
load:0x4ff33ce0,len:0x164c
load:0x4ff29ed0,len:0xd64
--- 0x4ff29ed0: esp_bootloader_get_description at /usr/share/esp-idf/components/esp_bootloader_format/esp_bootloader_desc.c:39
load:0x4ff2cbd0,len:0x3364
--- 0x4ff2cbd0: esp_flash_encryption_enabled at /usr/share/esp-idf/components/bootloader_support/src/flash_encrypt.c:89
entry 0x4ff29eda
--- 0x4ff29eda: call_start_cpu0 at /usr/share/esp-idf/components/bootloader/subproject/main/bootloader_start.c:25
I (8) boot: ESP-IDF v5.5 2nd stage bootloader
I (8) boot: compile time Aug 26 2025 12:21:17
I (9) boot: Multicore bootloader
I (10) boot: chip revision: v1.0
I (11) boot: efuse block revision: v0.3
I (11) boot.esp32p4: SPI Speed      : 80MHz
I (11) boot.esp32p4: SPI Mode       : DIO
I (12) boot.esp32p4: SPI Flash Size : 2MB
I (12) boot: Enabling RNG early entropy source...
I (13) boot: Partition Table:
I (13) boot: ## Label            Usage          Type ST Offset   Length
I (14) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (15) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (16) boot:  2 factory          factory app      00 00 00010000 00100000
I (17) boot: End of partition table
I (18) esp_image: segment 0: paddr=00010020 vaddr=40020020 size=0be98h ( 48792) map
I (27) esp_image: segment 1: paddr=0001bec0 vaddr=30100000 size=00044h (    68) load
I (28) esp_image: segment 2: paddr=0001bf0c vaddr=4ff00000 size=0410ch ( 16652) load
I (33) esp_image: segment 3: paddr=00020020 vaddr=40000020 size=1f134h (127284) map
I (52) esp_image: segment 4: paddr=0003f15c vaddr=4ff0410c size=0aaa8h ( 43688) load
I (61) esp_image: segment 5: paddr=00049c0c vaddr=4ff0ec00 size=01da4h (  7588) load
I (67) boot: Loaded app from partition at offset 0x10000
I (67) boot: Disabling RNG early entropy source...
I (69) cpu_start: Multicore app
I (78) cpu_start: Pro cpu start user code
I (78) cpu_start: cpu freq: 360000000 Hz
I (79) app_init: Application information:
I (79) app_init: Project name:     mcp23017_test
I (79) app_init: App version:      1
I (79) app_init: Compile time:     Aug 26 2025 12:21:12
I (80) app_init: ELF file SHA256:  7a8557ed0...
I (80) app_init: ESP-IDF:          v5.5
I (80) efuse_init: Min chip rev:     v0.1
I (80) efuse_init: Max chip rev:     v1.99
I (81) efuse_init: Chip rev:         v1.0
I (81) heap_init: Initializing. RAM available for dynamic allocation:
I (81) heap_init: At 4FF123E0 len 00028BE0 (162 KiB): RAM
I (82) heap_init: At 4FF3AFC0 len 00004BF0 (18 KiB): RAM
I (82) heap_init: At 4FF40000 len 00060000 (384 KiB): RAM
I (83) heap_init: At 50108080 len 00007F80 (31 KiB): RTCRAM
I (83) heap_init: At 30100044 len 00001FBC (7 KiB): TCM
W (84) spi_flash: winbond detected but related driver is not linked, please check option `SPI_FLASH_SUPPORT_WINBOND_CHIP`
I (85) spi_flash: detected chip: generic
I (85) spi_flash: flash io: dio
W (85) spi_flash: Detected size(16384k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (86) main_task: Started on CPU0
I (87) main_task: Calling app_main()
MCP23017 TEST
Running Device mcp23017 test, connect A-B port together...
I (88) i2c_bus: i2c0 bus inited
I (88) i2c_bus: I2C Bus V2 Config Succeed, Version: 1.1.0
E (289) i2c.master: I2C software timeout
E (289) i2c.master: s_i2c_synchronous_transaction(980): I2C transaction failed
E (289) i2c.master: i2c_master_transmit_receive(1283): I2C transaction failed
E (489) i2c.master: s_i2c_synchronous_transaction(980): I2C transaction failed
E (489) i2c.master: i2c_master_multi_buffer_transmit(1249): I2C transaction failed
E (689) i2c.master: I2C software timeout
E (689) i2c.master: s_i2c_synchronous_transaction(980): I2C transaction failed
E (689) i2c.master: i2c_master_transmit_receive(1283): I2C transaction failed
E (889) i2c.master: s_i2c_synchronous_transaction(980): I2C transaction failed
E (889) i2c.master: i2c_master_multi_buffer_transmit(1249): I2C transaction failed
./main/mcp23017_test.c:41:Device mcp23017 test, connect A-B port together:FAIL:Function [mcp23017][iot][device].  Expression Evaluated To FALSEMALLOC_CAP_8BIT: Before 602688 bytes free, After 601220 bytes free (delta -1468)

I (890) main_task: Returned from app_main()

More Information.

Enabling the I2C backward option it doesn't seems to run or at least don't report anything, just:

I (108) i2c_bus: i2c0 bus inited
I (108) i2c_bus: I2C Bus Config Succeed, Version: 1.1.0
./main/mcp23017_test.c:41:Device mcp23017 test, connect A-B port together:FAIL:Function [mcp23017][iot][device].  Expression Evaluated To FALSEMALLOC_CAP_8BIT: Before 598144 bytes free, After 597664 bytes free (delta -480)

I (909) main_task: Returned from app_main()

[YanKE01]

Please check the hardware connections.

I (25) boot: ESP-IDF v5.5-1-gb66b5448e0 2nd stage bootloader
I (26) boot: compile time Aug 27 2025 17:57:39
I (26) boot: Multicore bootloader
I (28) boot: chip revision: v0.1
I (30) boot: efuse block revision: v0.0
I (33) boot.esp32p4: SPI Speed      : 80MHz
I (37) boot.esp32p4: SPI Mode       : DIO
I (41) boot.esp32p4: SPI Flash Size : 2MB
I (44) boot: Enabling RNG early entropy source...
I (49) boot: Partition Table:
I (52) boot: ## Label            Usage          Type ST Offset   Length
I (58) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (64) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (71) boot:  2 factory          factory app      00 00 00010000 00100000
I (79) boot: End of partition table
I (81) esp_image: segment 0: paddr=00010020 vaddr=40020020 size=0beb8h ( 48824) map
I (98) esp_image: segment 1: paddr=0001bee0 vaddr=30100000 size=00044h (    68) load
I (99) esp_image: segment 2: paddr=0001bf2c vaddr=4ff00000 size=040ech ( 16620) load
I (107) esp_image: segment 3: paddr=00020020 vaddr=40000020 size=1f3bch (127932) map
I (133) esp_image: segment 4: paddr=0003f3e4 vaddr=4ff040ec size=0aab8h ( 43704) load
I (143) esp_image: segment 5: paddr=00049ea4 vaddr=4ff0ec00 size=01da4h (  7588) load
I (149) boot: Loaded app from partition at offset 0x10000
I (150) boot: Disabling RNG early entropy source...
I (161) cpu_start: Multicore app
I (171) cpu_start: Pro cpu start user code
I (171) cpu_start: cpu freq: 360000000 Hz
I (172) app_init: Application information:
I (172) app_init: Project name:     mcp23017_test
I (176) app_init: App version:      36792767f
I (180) app_init: Compile time:     Aug 27 2025 17:57:32
I (185) app_init: ELF file SHA256:  ca5b31eef...
I (189) app_init: ESP-IDF:          v5.5-1-gb66b5448e0
I (194) efuse_init: Min chip rev:     v0.1
I (198) efuse_init: Max chip rev:     v1.99 
I (202) efuse_init: Chip rev:         v0.1
I (206) heap_init: Initializing. RAM available for dynamic allocation:
I (212) heap_init: At 4FF123F0 len 00028BD0 (162 KiB): RAM
I (217) heap_init: At 4FF3AFC0 len 00004BF0 (18 KiB): RAM
I (222) heap_init: At 4FF40000 len 00060000 (384 KiB): RAM
I (228) heap_init: At 50108080 len 00007F80 (31 KiB): RTCRAM
I (233) heap_init: At 30100044 len 00001FBC (7 KiB): TCM
W (239) spi_flash: GigaDevice detected but related driver is not linked, please check option `SPI_FLASH_SUPPORT_GD_CHIP`
I (249) spi_flash: detected chip: generic
I (252) spi_flash: flash io: dio
W (255) spi_flash: Detected size(16384k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (268) main_task: Started on CPU0
I (289) main_task: Calling app_main()
MCP23017 TEST 


Press ENTER to see the list of tests.



Here's the test menu, pick your combo:
(1)     "Device mcp23017 test, connect A-B port together" [mcp23017][iot][device]

Enter test for running.
1
Running Device mcp23017 test, connect A-B port together...
I (1101) i2c_bus: i2c0 bus inited
I (1102) i2c_bus: I2C Bus V2 Config Succeed, Version: 1.1.0
GPIOA write = :4
GPIOB read = :4
GPIOA write = :3
GPIOB read = :3
GPIOA write = :2
GPIOB read = :2
GPIOA write = :1
GPIOB read = :1
GPIOA write = :0
GPIOB read = :0
I (2605) i2c_bus: i2c0 bus deinited
MALLOC_CAP_8BIT: Before 602672 bytes free, After 602568 bytes free (delta -104)
MALLOC_CAP_32BIT: Before 602672 bytes free, After 602568 bytes free (delta -104)
./main/mcp23017_test.c:74:Device mcp23017 test, connect A-B port together:PASS
Test ran in 1533ms

[stkw0]

Thank you for the fast reply. Certainly, I was checking with a coworker and seems there is some bug with the board itself.

[stkw0]

After fixing the hardware issue we checked that the I2C was working with a different I2C peripheral and then tried again with the MCP23017, but we still have timeouts. When using the newer driver it seems that it fails on the mcp23017_check_present function. We checked with an oscilloscope that it writes correctly but when reading it doesn't works correctly. The SCL and SDA seems to be out of sync as seen in the image (I am sorry for the bad image quality).

When enabling I2C_BUS_BACKWARD_CONFIG the mcp23017_check_present seems to work correctly but it fails the unit test as seen in the next log.

I (8) boot: ESP-IDF v5.5.1 2nd stage bootloader
I (9) boot: compile time Sep  4 2025 11:51:39
I (9) boot: Multicore bootloader
I (10) boot: chip revision: v1.0
I (11) boot: efuse block revision: v0.3
I (11) boot.esp32p4: SPI Speed      : 80MHz
I (12) boot.esp32p4: SPI Mode       : DIO
I (12) boot.esp32p4: SPI Flash Size : 2MB
I (13) boot: Enabling RNG early entropy source...
I (13) boot: Partition Table:
I (13) boot: ## Label            Usage          Type ST Offset   Length
I (14) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (15) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (16) boot:  2 factory          factory app      00 00 00010000 00100000
I (17) boot: End of partition table
I (18) esp_image: segment 0: paddr=00010020 vaddr=40020020 size=0b314h ( 45844) map
I (26) esp_image: segment 1: paddr=0001b33c vaddr=30100000 size=00044h (    68) load
I (28) esp_image: segment 2: paddr=0001b388 vaddr=4ff00000 size=04c90h ( 19600) load
I (33) esp_image: segment 3: paddr=00020020 vaddr=40000020 size=19ee0h (106208) map
I (49) esp_image: segment 4: paddr=00039f08 vaddr=4ff04c90 size=09350h ( 37712) load
I (57) esp_image: segment 5: paddr=00043260 vaddr=4ff0e000 size=01ed8h (  7896) load
I (62) boot: Loaded app from partition at offset 0x10000
I (63) boot: Disabling RNG early entropy source...
I (67) cpu_start: Multicore app
I (76) cpu_start: Pro cpu start user code
I (76) cpu_start: cpu freq: 360000000 Hz
I (77) app_init: Application information:
I (77) app_init: Project name:     mcp23017_test
I (77) app_init: App version:      1
I (77) app_init: Compile time:     Sep  4 2025 11:52:47
I (78) app_init: ELF file SHA256:  690984e24...
I (78) app_init: ESP-IDF:          v5.5.1
I (78) efuse_init: Min chip rev:     v0.1
I (78) efuse_init: Max chip rev:     v1.99
I (79) efuse_init: Chip rev:         v1.0
I (79) heap_init: Initializing. RAM available for dynamic allocation:
I (79) heap_init: At 4FF11850 len 00029770 (165 KiB): RAM
I (80) heap_init: At 4FF3AFC0 len 00004BF0 (18 KiB): RAM
I (80) heap_init: At 4FF40000 len 00060000 (384 KiB): RAM
I (80) heap_init: At 50108080 len 00007F80 (31 KiB): RTCRAM
I (81) heap_init: At 30100044 len 00001FBC (7 KiB): TCM
I (82) spi_flash: detected chip: generic
I (82) spi_flash: flash io: dio
W (82) spi_flash: Detected size(16384k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
W (83) i2c: This driver is an old driver, please migrate your application code to adapt `driver/i2c_master.h`
I (84) main_task: Started on CPU0
I (85) main_task: Calling app_main()
MCP23017 TEST
Running Device mcp23017 test, connect A-B port together...
I (86) i2c_bus: i2c0 bus inited
I (86) i2c_bus: I2C Bus Config Succeed, Version: 1.1.0
GPIOA write = :4
GPIOB read = :5f
./main/mcp23017_test.c:76:Device mcp23017 test, connect A-B port together:FAIL: Expected 4 Was 95. Function [mcp23017][iot][device]MALLOC_CAP_8BIT: Before 605648 bytes free, After 605168 bytes free (delta -480)

I (5090) main_task: Returned from app_main()

At the moment of the failure with the legacy driver, the SCL and SDA at least seems to be in sync as seen in the image.

This is the sdkconfig used, only changing I2C_BUS_BACKWARD_CONFIG between the two tests.
sdkconfig.gz

For the purpose of testing, could you share your source code and sdkconfig? Given that in your test seems the esp32p4 was also used, maybe I could try to directly flash the same binary firmware?

[stkw0]

@YanKE01 I have been debugging a bit more and seems that by default the MCP23017 is in sequential mode but the library seems to be accessing MCP23017 as if it was in byte mode¿? Changing it to read and write 16bits values is capable at least to pass the basic mcp23017_check_present .

Also I was surprised to see that the i2c driver emits two READ commands even if a single byte is read:

    i2c_operation_t i2c_ops[] = {
        {.hw_cmd = I2C_TRANS_START_COMMAND},
        {.hw_cmd = I2C_TRANS_WRITE_COMMAND(i2c_dev->ack_check_disable ? false : true), .data = (uint8_t *)write_buffer, .total_bytes = write_size},
        {.hw_cmd = I2C_TRANS_START_COMMAND},
        {.hw_cmd = I2C_TRANS_READ_COMMAND(I2C_ACK_VAL), .data = read_buffer, .total_bytes = read_size - 1}, 
        {.hw_cmd = I2C_TRANS_READ_COMMAND(I2C_NACK_VAL), .data = (read_buffer + read_size - 1), .total_bytes = 1},
        {.hw_cmd = I2C_TRANS_STOP_COMMAND},
    };

For one single byte read, couldn't this cause weird a behavior as the one I was seeing in the oscilloscope?

[YanKE01]

Hi, @stkw0 . You can extract the firmware below and run the tests. I performed the verification on an ESP32-P4-FUNCTION-EV-BOARD. The connected MCP23017 is an off-the-shelf module—you can click here to view it. On the hardware side, SCL is GPIO5 and SDA is GPIO6.

esptool.py -p /dev/ttyUSB0 write_flash 0x0 merged-binary.bin

merged-binary.zip

[stkw0]

We have the SCL and SDA pins soldered, can you share the source code to built it?

We confirmed our hardware works properly and using a different library ( https://github.com/UncleRus/esp-idf-lib/tree/master/components/mcp23x17 ) it can communicate with the mcp23017 chip. The only difference between that library and this one, is that the one that works only reads and writes 16 bits registers and the one that doesn't reads and writes 8 bits

[YanKE01]

We have the SCL and SDA pins soldered, can you share the source code to built it?

We confirmed our hardware works properly and using a different library ( https://github.com/UncleRus/esp-idf-lib/tree/master/components/mcp23x17 ) it can communicate with the mcp23017 chip. The only difference between that library and this one, is that the one that works only reads and writes 16 bits registers and the one that doesn't reads and writes 8 bits

My test code is just test_apps, with only minor modifications.

[stkw0]

May it be that your local i2c_bus component is a different version or have uncommitted fixes that make it work?

[YanKE01]

May it be that your local i2c_bus component is a different version or have uncommitted fixes that make it work?

The i2c_bus implementation in the current master is located at components/i2c_bus, with version 1.4.2.

[stkw0]

My test code is just test_apps, with only minor modifications.

Cloning this repository and running the test_app from master branch it gives

MCP23017 TEST
Running Device mcp23017 test, connect A-B port together...
E (278) i2c.master: this port has not been initialized, please initialize it first
I (279) i2c_bus: i2c0 bus inited
I (279) i2c_bus: I2C Bus V2 Config Succeed, Version: 1.4.2
E (483) i2c.master: I2C software timeout
E (483) i2c.master: s_i2c_synchronous_transaction(980): I2C transaction failed
E (483) i2c.master: i2c_master_transmit_receive(1283): I2C transaction failed
E (690) i2c.master: I2C software timeout
E (690) i2c.master: s_i2c_synchronous_transaction(980): I2C transaction failed
E (690) i2c.master: i2c_master_transmit_receive(1283): I2C transaction failed

Note than the E (278) i2c.master: this port has not been initialized, please initialize it first was not showing in previous tests

I also tried to use different esp-idf version (5.3.4, 5.4.2 and 5.5.1). At this point I don't know how to debug this library further. The only remaining difference is that we used the Olimex esp32-p4-devkit.

[stkw0]

(sorry, previously I got confused and thought the other issue was this one)

I noticed that the writes seems to work but the reads didn't. It may be related with a bug I reported on esp-idf which was reproduced and fixed. See espressif/esp-idf#16231

EDIT: I removed that patch (which I was applying for some time) and by removing that patch the timeouts disappeared, thought it still fails with

GPIOA write = :4
GPIOB read = :5f
./main/mcp23017_test.c:69:Device mcp23017 test, connect A-B port together:FAIL: Expected 4 Was 95. 

EDIT2: Now I properly understand what was happening. Due to that patch, it was causing an error when reading the MCP23017 with the new driver. With the old driver, it was fine since that patch was ineffective. Still, that patch is needed to read another sensor. So I guess this issue should be migrated to esp-idf. Should I open an issue on esp-idf?