ESP32S3 esp_http_client_open does not timeout (IDFGH-13279)
Answers checklist.
- [X] I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
- [X] I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
- [X] I have searched the issue tracker for a similar issue and not found a similar issue.
IDF version.
v5.2.2
Espressif SoC revision.
ESP32-S3
Operating System used.
macOS
How did you build your project?
VS Code IDE
If you are using Windows, please specify command line type.
None
Development Kit.
Custom board
Power Supply used.
Battery
What is the expected behavior?
I expect the esp_http_client_open call to timeout within the timeout_ms milliseconds.
What is the actual behavior?
It does not timeout, so the watchdog is triggered.
Steps to reproduce.
This is happening due to unstable power supply on my board which is causing HTTP transmission errors. However, it should still timeout I believe within the timeout_ms time.
set timeout_ms = 5000 is_async = false
(Watchdog timeout is set to 10sec) Run the code and attempt to open an https connection.
Debug Logs.
Stacktrace from GDB when the watchdog timeout fires:
#0 0x400559e0 in ?? ()
#1 0x40384a76 in vPortClearInterruptMaskFromISR (prev_level=<optimized out>) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/include/freertos/portmacro.h:564
#2 vPortExitCritical (mux=0x3fcce92c) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:504
#3 0x4038432d in xQueueReceive (xQueue=0x3fcce8d8, pvBuffer=0x3fcb11e8 <processingTaskStack+22808>, xTicksToWait=<optimized out>) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/freertos/FreeRTOS-Kernel/queue.c:1632
#4 0x42064f5c in sys_arch_mbox_fetch (mbox=<optimized out>, msg=0x3fcb11e8 <processingTaskStack+22808>, timeout=5000) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/lwip/port/freertos/sys_arch.c:317
#5 0x420661ca in netconn_recv_data (conn=0x3c15605c, new_buf=0x3fcb1298 <processingTaskStack+22984>, apiflags=8 '\b') at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/lwip/lwip/src/api/api_lib.c:615
#6 0x42066301 in netconn_recv_data_tcp (conn=0x3c15605c, new_buf=0x3fcb1298 <processingTaskStack+22984>, apiflags=8 '\b') at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/lwip/lwip/src/api/api_lib.c:727
#7 0x420663ac in netconn_recv_tcp_pbuf_flags (conn=0x3c15605c, new_buf=0x3fcb1298 <processingTaskStack+22984>, apiflags=8 '\b') at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/lwip/lwip/src/api/api_lib.c:808
#8 0x420688d7 in lwip_recv_tcp (sock=0x3c138c4c, mem=0x3c1586c4, len=<optimized out>, flags=0) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/lwip/lwip/src/api/sockets.c:951
#9 0x42069c5b in lwip_recvfrom (s=54, mem=0x3c1586c4, len=5423, flags=0, from=0x0, fromlen=0x0) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/lwip/lwip/src/api/sockets.c:1218
#10 0x42069d25 in lwip_read (s=54, mem=0x3c1586c4, len=5423) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/lwip/lwip/src/api/sockets.c:1260
#11 0x420063e0 in esp_vfs_read (r=0x3fcb1938 <processingTaskBuffer+104>, fd=<optimized out>, dst=0x3c1586c4, size=5423) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/vfs/vfs.c:508
#12 0x420cc311 in read (fd=54, buf=0x3c1586c4, cnt=5423) at /builds/idf/crosstool-NG/.build/HOST-x86_64-apple-darwin21.1/xtensa-esp-elf/src/newlib/newlib/libc/syscalls/sysread.c:11
#13 0x4207cebd in mbedtls_net_recv (ctx=0x3fcf103c, buf=0x3c1586c4 "", len=5423) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/mbedtls/port/net_sockets.c:351
#14 0x42073dfd in mbedtls_ssl_fetch_input (ssl=0x3fcf0cc4, nb_want=11003) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/mbedtls/mbedtls/library/ssl_msg.c:2310
#15 0x42074b43 in ssl_get_next_record (ssl=0x3fcf0cc4) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/mbedtls/mbedtls/library/ssl_msg.c:4937
#16 0x42074c45 in mbedtls_ssl_read_record (ssl=0x3fcf0cc4, update_hs_digest=1) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/mbedtls/mbedtls/library/ssl_msg.c:4214
#17 0x4207743b in mbedtls_ssl_parse_certificate (ssl=0x3fcf0cc4) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/mbedtls/mbedtls/library/ssl_tls.c:8203
#18 0x4207a276 in mbedtls_ssl_handshake_client_step (ssl=0x3fcf0cc4) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/mbedtls/mbedtls/library/ssl_tls12_client.c:3523
#19 0x42076461 in mbedtls_ssl_handshake_step (ssl=0x3fcf0cc4) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/mbedtls/mbedtls/library/ssl_tls.c:4546
#20 0x420764ee in mbedtls_ssl_handshake (ssl=0x3fcf0cc4) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/mbedtls/mbedtls/library/ssl_tls.c:4610
#21 0x4206ee59 in esp_mbedtls_handshake (tls=0x3fcf0cc4, cfg=0x3fcf0704) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/esp-tls/esp_tls_mbedtls.c:218
#22 0x4206e44c in esp_tls_handshake (tls=0x3fcf0cc4, cfg=0x3fcf0704) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/esp-tls/esp_tls.c:118
#23 0x4206e6cd in esp_tls_low_level_conn (hostname=<optimized out>, hostlen=39, port=443, cfg=0x3fcf0704, tls=0x3fcf0cc4) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/esp-tls/esp_tls.c:497
#24 0x4206e81c in esp_tls_conn_new_sync (hostname=0x3fcf0794 "us-central1-smartaed.cloudfunctions.net", hostlen=39, port=443, cfg=0x3fcf0704, tls=0x3fcf0cc4) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/esp-tls/esp_tls.c:528
#25 0x420c0cff in ssl_connect (t=0x3fcf0698, host=0x3fcf0794 "us-central1-smartaed.cloudfunctions.net", port=443, timeout_ms=5000) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/tcp_transport/transport_ssl.c:111
#26 0x420dfee4 in esp_transport_connect (t=0x3fcf0698, host=0x3fcf0794 "us-central1-smartaed.cloudfunctions.net", port=443, timeout_ms=5000) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/tcp_transport/transport.c:123
#27 0x420702e6 in esp_http_client_connect (client=<optimized out>) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/esp_http_client/esp_http_client.c:1402
#28 0x42070f66 in esp_http_client_open (client=<optimized out>, write_len=888) at /Users/MYHOMEDIR/esp/v5.2.2/esp-idf/components/esp_http_client/esp_http_client.c:1559
#29 0x4200ad13 in OpenClientConnection () at MY CODE
More Information.
No response
Hello @danfleck Could you please share a sample application with sdkconfig file that can be used to reproduce this issue. Thanks!
Here is a modified example program that shows the problem. The timeouts are very short because on working hardware, the connection doesn't really timeout. The watchdog timeout is 500ms and the http_open timeout is 300ms. When I run this on an ESP dev board the watchdog timeout runs, not the http_open timeout. I'm not sure if this is representative of the exact problem I am seeing because on my board the timeouts are 10s and 5s.
(Make sure to not init the task watchdog on startup in sdkconfig.)
SDKCONFIG sdkconfig.txt
Hello @danfleck,
Any specific reason you have used esp_task_wdt.h APIs' or just to create reproducible case?
Also, I wanted to point out that the timeout you set in esp_http_client_config_t doesn't directly apply to the esp_http_client_open() API. Instead, it applies individually to various socket-related calls made internally. As a result, esp_http_client_open() might take longer than the watchdog timeout you've set in your code.
Hil @nileshkale123 , Yes, I just used the esp_task_wdt.h API to create the test case. My real code uses them also, but as part of the whole program.
Thanks for the information about the timeouts. Is there a way to set the total timeout for esp_http_client_open ? Or is there a way to know the total timeouts for the entire call? I'd like to know so I can set the watchdog to an appropriate value with enough extra to make sure it doesn't trip the watchdog on failure.
Thanks!
Is there a way to set the total timeout for esp_http_client_open ? Or is there a way to know the total timeouts for the entire call?
Maybe @david-cermak @ESP-YJM can help to answer this question?
@danfleck It seems the TLS session cost much time and your wantchdog timeout is too small that make task watchdog trigger. If your http is no TLS, the timeout may take effect, because it only need do TCP three-handshake, and the time out can be calucated in esp_tls_conn_new_sync. But if your http is TLS, the function esp_tls_low_level_conn will not return until your TLS is finished. So suggest your watchdog time to default time(If i remember right, it is 5 seconds).
Thanks for your comments. On my real board the watchdog timeout is 10seconds and the HTTP timeout is 5 seconds. The problem is that sometimes the watchdog timeout fires before the HTTP timeout. It is using a TLS connection. I just want to set the HTTP timeout so it happens before the watchdog timeout, but I don't know the right value to make sure that happens. Thanks for your help!
The HTTP timeout contains the TCP three-way handshake,TLS handshake(If HTTPS) and HTTP request, so it can't only set for HTTP request. But if your watchdog timeout has already set to 10seconds and still trigger, it may some problems. Do you enable hardware AES , MPI and SHA in mbedlts components?
Yes, I did fix the overall problem, so this doesn’t happen anymore on my board. However, I still think that if there is an HTTP problem, I want the HTTP timeout to happen and not the watchdog timeout. That is what I want to solve. What setting to use for the HTTP timeout to make sure if there is an TLS or HTTP problem, the HTTP timeout happens, not the watchdog.
It sounds like the timeout setting for http is not what I want so I’ll need to make my own using a Timer.
Thanks for your help!
From: ESP-YJM @.> Date: Sunday, November 10, 2024 at 10:56 PM To: espressif/esp-idf @.> Cc: Dan F. @.>, Mention @.> Subject: Re: [espressif/esp-idf] ESP32S3 esp_http_client_open does not timeout (IDFGH-13279) (Issue #14209)
The HTTP timeout contains the TCP three-way handshake,TLS handshake(If HTTPS) and HTTP request, so it can't only set for HTTP request. But if your watchdog timeout has already set to 10seconds and still trigger, it may some problems. Do you enable hardware AES , MPI and SHA in mbedlts components?
— Reply to this email directly, view it on GitHubhttps://github.com/espressif/esp-idf/issues/14209#issuecomment-2467181693, or unsubscribehttps://github.com/notifications/unsubscribe-auth/ABEC2NWNC5F3D4FTZII7P5D2AATHBAVCNFSM6AAAAABLBJILOSVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDINRXGE4DCNRZGM. You are receiving this because you were mentioned.Message ID: @.***>
Hello @danfleck ,
I am closing this issue for now. However, please feel free to reopen it if needed.