InstrFetchProhibited with in IDFv5 upgrade from IDFv4.4

[Hamzah Hajeir]

Hi there,
I've an issue that existed since I updated to ESP-IDF v5.0 (7+ months), which is a strange exception after calling a specific function from mbedtls.

Brief:
I'm the maintainer of H4 stack libraries, that includes a timer scheduler (H4), TCP wrapper to LwIP Raw APIs (H4AsyncTCP), MQTT client (H4AsyncMQTT), Webserver (H4AsyncWebServer), HTTP Client (ArmadilloHTTP) -Should be renamed -, and finally the complete system: H4Plugins, that enables someone to make SONOFF-like functionality out of few lines.

In H4AsyncTCP, I've supported TLS by utilizing LwIP feature: ALTCP (Application-Layered TCP)[1].

In IDF v4.4.5 (Arduino v2.0.11) all went perfectly, projects show high reliability over high stress tests.

However, upgrading to ESP-IDF v5.0 which is accompanied with several major upgrades:

• GCC compiler, from 8.4.0 to 12.2.0.

• MbedTLS, from 2.28.3 to 3.x.

• ESP-IDF itself.

With other minor changes, to:

• LwIP, from 2.1.2 to 2.1.3.

• esp-lwip fork, which was a bugfix of upstream lwip regarding TLS. However, the change is limited to upgrading issues.

• The projects themselves (Checkout the MCVEs in the raised issue [2]).

The issue is an InstrFetchProhibited after a call done to `mbedtls_ssl_read()` within the LwIP file: altcp_tls_mbedtls.

My conclusion was its either a bug with Xtensa GCC compiler upgrade, ESP-IDF upgrade, or MbedTLS upgrade.
What do you think?
Have I missed something?

[1] https://www.nongnu.org/lwip/2_1_x/group ... __api.html
[2] https://github.com/espressif/esp-idf/issues/13335

[MicroController]

The issue is an InstrFetchProhibited...

My conclusion was its either a bug with Xtensa GCC compiler upgrade, ESP-IDF upgrade, or MbedTLS upgrade.
What do you think?
Have I missed something?

InstrFetchProhibited may be due to an invalid/corrupt function pointer being called. Reason for that could be any kind of memory/stack corruption happening.
Especially after upgrading IDF and toolchain, it may be worth trying to increase tasks' stack sizes and to enable stack overflow checking if not done already.

[Hamzah Hajeir]

InstrFetchProhibited may be due to an invalid/corrupt function pointer being called. Reason for that could be any kind of memory/stack corruption happening.
Especially after upgrading IDF and toolchain, it may be worth trying to increase tasks' stack sizes and to enable stack overflow checking if not done already.

Thanks for your suggestion, I've increased the stack size to 10000 and enabled stack overflow check, nothing had to change.

But a probable useful founding is the usage of custom PBUFs management in ESP-IDF v5.0 [1].

What have led me here is an added debug print before the line it mostly crashes: calling `custom_free_function()` in the concerned buffer.

Here I find it being corrupted after freeing the second buffer, which is chained.

Code: [Select all] [Expand/Collapse]

1. pbuf_free(0x3fcb341c)
2. pbuf_free: deallocating 0x3fcb341c
3. pbuf_free: custom_free_function 0x4207595c
4. 0x4207595c: esp_pbuf_free at C:/Users/Hamza/esp/esp-idf/components/esp_netif/lwip/netif/esp_pbuf_ref.c:34
5.  
6. pbuf_free(0x3fcbc3a8)
7. pbuf_free: deallocating 0x3fcbc3a8
8. pbuf_free: custom_free_function 0x5f207525
9. Guru Meditation Error: Core  1 panic'ed (IllegalInstruction). Exception was unhandled.
10.  
11. Core  1 register dump:
12. PC      : 0x5f207525  PS      : 0x00060930  A0      : 0x8202693e  A1      : 0x3fca8980
13. A2      : 0x3fcbc3a8  A3      : 0x5f207525  A4      : 0x00000000  A5      : 0x00000000
14. A6      : 0x00000000  A7      : 0x3fcbc3a8  A8      : 0x820169c7  A9      : 0x3fca8930  
15. A10     : 0x3fcbc3a8  A11     : 0x3fca8ca8  A12     : 0x0000001a  A13     : 0x000005ec
16. A14     : 0x00000182  A15     : 0x00000000  SAR     : 0x0000000a  EXCCAUSE: 0x00000000  
17. EXCVADDR: 0x00000000  LBEG    : 0x400556d5  LEND    : 0x400556e5  LCOUNT  : 0xffffffff

GeSHi © Codebox Plus Extension

And however, I've created another pbuf, assign some data to it, freeing it happens to fail:

Code: [Select all] [Expand/Collapse]

1. pbuf_free(0x3fcbb260)
2. pbuf_free: deallocating 0x3fcbb260
3. pbuf_free: custom_free_function 0x4207598c
4. 0x4207598c: esp_pbuf_free at C:/Users/Hamza/esp/esp-idf/components/esp_netif/lwip/netif/esp_pbuf_ref.c:34
5.  
6. Allocating another buffer, then freeing it immediately
7. pbuf_alloc(length=1516)
8. pbuf_alloc(length=1516) == 0x3fcbbfb4
9. pbuf_free(0x3fcbbfb4)
10. pbuf_free: deallocating 0x3fcbbfb4
11. pbuf_free(0x3fcba7cc)
12. pbuf_free: deallocating 0x3fcba7cc
13. pbuf_free: custom_free_function 0x3fcba82c

GeSHi © Codebox Plus Extension

Is it of any relevance?

[1] https://github.com/espressif/esp-idf/co ... 0fc9328226

[ESP_Sprite]

ESP-IDF should give you a backtrace for that crash; if you run 'idf.py monitor' as your terminal it should automatically be decoded into something readable. What does that say?

Also, the PC in the crash is '%u _' in ascii, so whatever function pointer you're overwriting, it seems to be overwritten with a printf format string. Perhaps that helps?

[MicroController]

Code: Select all

pbuf_free: deallocating 0x3fcba7cc
pbuf_free: custom_free_function 0x3fcba82c

This looks interesting... custom_free_function seems to plausibly be a pointer to another data structure here. May be coincidence though.

Another thing to check could be: When updating a library you must make sure that all code using any of that library's header files is recompiled. If you happen to be linking in a previously compiled .a that can also cause this kind of issues.

[Hamzah Hajeir]

ESP-IDF should give you a backtrace for that crash; if you run 'idf.py monitor' as your terminal it should automatically be decoded into something readable. What does that say?

Also, the PC in the crash is '%u _' in ascii, so whatever function pointer you're overwriting, it seems to be overwritten with a printf format string. Perhaps that helps?

The decoder works, but it either doesn't provide a stack, or points to pbuf_free() call, or stops at the assertion of:

Code: Select all

        LWIP_ASSERT("pc->custom_free_function != NULL", pc->custom_free_function != NULL);

Had to use debugger, it always went undefined behaviour on calling `pc->custom_free_function(p);`.

Per the printing part, I had to insert it to read what it points to; because it was failing there at debugging, and yesterday (until now) couldn't run the debugger again (Something goes wrong), so had to print.

[Hamzah Hajeir]

Code: Select all

pbuf_free: deallocating 0x3fcba7cc
pbuf_free: custom_free_function 0x3fcba82c

This looks interesting... custom_free_function seems to plausibly be a pointer to another data structure here. May be coincidence though.

Another thing to check could be: When updating a library you must make sure that all code using any of that library's header files is recompiled. If you happen to be linking in a previously compiled .a that can also cause this kind of issues.

Yes, and if you've noticed, it had changed its value just before been printed.

Code: [Select all] [Expand/Collapse]

1. pbuf_free: custom_free_function 0x4207598c
2. 0x4207598c: esp_pbuf_free at C:/Users/Hamza/esp/esp-idf/components/esp_netif/lwip/netif/esp_pbuf_ref.c:34

GeSHi © Codebox Plus Extension

I always clean the build, especially if any major change has taken place.

((Had issues using ESP32 forum, as I receive Error messages of posting and even deletion of the repeated replies)).

[Hamzah Hajeir]

Hi all

It seems to be the custom_free_function developed by Espressif's lately (The commit I've mentioned in a reply).

See: https://github.com/espressif/esp-idf/is ... 2104864696