Esp-idf: [TW#27105] stop httpd will stuck all the time when recevie wifi disconnect event.

[outermanle]

Environment

• Development Kit: [ESP32-DevKitC]
• Kit version (for WroverKit/PicoKit/DevKitC): [v4]
• Core (if using chip or module): [ESP-WROOM-32D]
• IDF version (3276a1316):
• Development Env: [Make]
• Operating System: [Ubuntu]
• Power Supply: [USB]

Problem Description

stop httpd will stuck when wifi disconnect.

code refer to examples/protocols/http_server/simple/main/main.c

Expected Behavior

Normally works.

Actual Behavior

sometimes httpd stop will stuck all the time.

Steps to repropduce

test 24 hours reproduce this issue, the probability is about 1-10%.

Debug Logs

```c
while (hd->hd_td.status != THREAD_STOPPED) {
httpd_os_thread_sleep(1000);
ESP_LOGW(TAG, "stopping httpd status(%d)...", hd->hd_td.status);
}

I (134462841) httpd: stopping httpd status(32768)...
I (134463841) httpd: stopping httpd status(32768)...
I (134464841) httpd: stopping httpd status(32768)...
I (134465841) httpd: stopping httpd status(32768)...
I (134466841) httpd: stopping httpd status(32768)...
I (134467841) httpd: stopping httpd status(32768)...
I (134468841) httpd: stopping httpd status(32768)...

```c

[anurag-kar]

@outermanle Thanks for pointing out this issue. We'll try to resolve this as soon as possible

[outermanle]

Thanks for your quick response.

During wifi status change, the ctrl sock(ctrl_fd) no response and server maybe not receive the shutdown msg.

[anurag-kar]

During wifi status change, the ctrl sock(ctrl_fd) no response and server maybe not receive the shutdown msg.

@outermanle That's one possibility.

But the status value printed is 32768, while status is an enum with only 4 possible values (0 to 3) and has a well defined value while the server is running. I suspect it has to do with the server handle, which could have gone invalid, though again that seems highly unlikely as handle is set to NULL when server stops.

[outermanle]

I also doubt the status value with 32768, uint16_t -1 ?

[anurag-kar]

@outermanle enums in this case of esp32 platform is int32_t

[outermanle]

I got the previous log, before add the status printed. It may be helpful. @anurag-kar

I (15264377) wifi: state: run -> init (0)
I (15264377) wifi: pm stop, total sleep time: 13383921111 us / 15262497096 us
I (15264377) wifi: n:1 0, o:1 1, ap:255 255, sta:1 1, prof:1
I (15264387) wifi: SYSTEM_EVENT_STA_DISCONNECTED
W (15264387) httpd_txrx: httpd_default_recv: error in recv = 113
I (15264397) wifi: disconnect reason: Assoc leave(8)
W (15264407) httpd_txrx: httpd_resp_send_err: 408 Request Timeout - Server closed this connection
I (15264407) wifi: send SYSTEM_EVENT_STA_DISCONNECTED succeed.
I (15264407) queue-srv: ACTION_WIFI_DISCONNECTED
W (15264417) httpd_txrx: httpd_default_send: error in send = 113
W (15264437) httpd: httpd stopping
I (15264437) httpd: httpd_stop: begin to sent control msg to stop server
W (15264447) httpd_txrx: httpd_default_recv: error in recv = 113
I (15264457) httpd: httpd_stop: sent control msg to stop server.
W (15264467) httpd_txrx: httpd_resp_send_err: 408 Request Timeout - Server closed this connection
W (15264467) httpd_txrx: httpd_default_send: error in send = 113
W (15264477) httpd_txrx: httpd_default_recv: error in recv = 113
W (15264487) httpd_txrx: httpd_resp_send_err: 408 Request Timeout - Server closed this connection
W (15264497) httpd_txrx: httpd_default_send: error in send = 113
I (15265467) httpd: stopping httpd...
I (15266467) httpd: stopping httpd...
I (15267467) httpd: stopping httpd... （while sleep 1s）
I (15268467) httpd: stopping httpd...
I (15269467) httpd: stopping httpd...
I (15270467) httpd: stopping httpd...
I (15271467) httpd: stopping httpd...
I (15272467) httpd: stopping httpd...
I (15273467) httpd: stopping httpd...

[anurag-kar]

@outermanle Thanks.

Is this for examples/protocols/http_server/simple?

[outermanle]

yes, I refer to this example and implement myself logic get/post handler.

[anurag-kar]

I see. If there is more log, that'll be helpful.

Are you sure that httpd_stop() is not called twice with the same handle (could happen if SYSTEM_EVENT_STA_DISCONNECTED is triggered twice)? Calling httpd_stop() on an invalid handle will cause undefined behavior.

To avoid such situation the handle is assigned NULL, right after httpd_stop() is called, like it's done in the event_handler in examples/protocols/http_server/simple

[outermanle]

yes, I have done this protection to prevent call twice.

wifi disconnected event

    if (httpd_server != NULL) {
        stop_webserver(httpd_server);
        httpd_server = NULL;
    }

wifi connected event

     if (httpd_server == NULL) {
            httpd_server = start_webserver();
        }

[anurag-kar]

@outermanle I'll try to reproduce this situation. Hopefully get some insight out of that

[outermanle]

@anurag-kar

Thanks.
Here is my test procedure:

1. wifi connected and delay 1-2 minutes then disconnect, repeat this.
2. open browser and request one page to httpd and then do nothing.

[outermanle]

@anurag-kar
Can you provide debug patch? I can add it and reproduce it at the same time.

[anurag-kar]

Can you provide debug patch? I can add it and reproduce it at the same time.

Thanks a lot. I've been trying to reproduce it with the simple example but still no luck.

You can try with this patch. Send me the full log if possible (attach log file if too long).

[outermanle]

I do some tweaks to it, if I change status to 2 and still restore to 65536.
I doubt if this heap boundary leak or wild pointer issue.

tweak code, active delete task if timeout

esp_err_t httpd_stop(httpd_handle_t handle)
{
    struct httpd_data *hd = (struct httpd_data *) handle;
    if (hd == NULL) {
        return ESP_ERR_INVALID_ARG;
    }
    int retry = 3;
    struct httpd_ctrl_data msg;
    memset(&msg, 0, sizeof(msg));
    msg.hc_msg = HTTPD_CTRL_SHUTDOWN;
    //ESP_LOGI(TAG, LOG_FMT("begin to sent control msg to stop server"));
    ESP_LOGW(TAG, LOG_FMT("server thread status before stopping = %d"), hd->hd_td.status);
    /* TODO: if blocked here then set hd->hd_td.status = THREAD_STOPPING; */
    cs_send_to_ctrl_sock(hd->msg_fd, hd->config.ctrl_port, &msg, sizeof(msg));
    ESP_LOGI(TAG, LOG_FMT("sent control msg to stop server."));
    while (hd->hd_td.status != THREAD_STOPPED) {
        httpd_os_thread_sleep(1000);
        if (retry-- == 0) {
            /* allow 3 seconds to process, oresle set directly. */
            ESP_LOGW(TAG, LOG_FMT("Timeout to stop server, set directly!"));
            hd->hd_td.status = THREAD_STOPPING;
        }
        ESP_LOGW(TAG, "stopping httpd status(%d)...", hd->hd_td.status);

        if (retry < 0) {
            if (hd->hd_td.status > THREAD_STOPPED) {
                ESP_LOGE(TAG, "pointer issue? fatal err!");
            }
            hd->hd_td.status = THREAD_STOPPING;
            vTaskDelay(22000/portTICK_PERIOD_MS);
            ESP_LOGE(TAG, "reset status again, httpd status(%d)...", hd->hd_td.status);

            if (hd->msg_fd != -1) close(hd->msg_fd);
            if (hd->ctrl_fd != -1) cs_free_ctrl_sock(hd->ctrl_fd);
            httpd_close_all_sessions(hd);// crash here
            if (hd->listen_fd != -1) close(hd->listen_fd);
            hd->hd_td.status = THREAD_STOPPED;
            ESP_LOGW(TAG, LOG_FMT("begin to delete httpd task"));
            if (hd->hd_td.handle != NULL) {
                ESP_LOGW(TAG, LOG_FMT("delete httpd task"));
                vTaskDelete(hd->hd_td.handle);
                hd->hd_td.handle = NULL;
                break;
            } else {
                ESP_LOGW(TAG, LOG_FMT("already delete httpd task"));
            }
        }
    }

    ESP_LOGI(TAG, LOG_FMT("server stopped"));
    httpd_delete(hd);
    return ESP_OK;
}

crash log

I (119938306) wifi: state: run -> auth (ec0)
I (119938306) wifi: pm stop, total sleep time: 73227332878 us / 86401065378 us
I (119938306) wifi: n:6 0, o:6 0, ap:255 255, sta:6 0, prof:1
I (119938316) wf: SYSTEM_EVENT_STA_DISCONNECTED
I (119938316) wf: disconnect reason: Mic failure(14)
I (119938326) que: ACTION_WIFI_DISCONNECTED
Interface not up, skipping 0x3ffd1f94
W (119938336) httpd: httpd stopping
I (119938336) httpd: httpd_stop: begin to sent control msg to stop server
I (119938346) httpd: httpd_stop: sent control msg to stop server.
Interface not up, skipping 0x3ffd1f94
W (119939356) httpd: stopping httpd status(65535)...
W (119940356) httpd: stopping httpd status(65535)...
W (119941356) httpd: stopping httpd status(65535)...
W (119942356) httpd: httpd_stop: Timeout to stop server, set directly!
W (119942356) httpd: stopping httpd status(2)...
E (119954356) httpd: reset status again, httpd status(65535)...
Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.
Core 0 register dump:
PC      : 0x4016621e  PS      : 0x00060b30  A0      : 0x80136038  A1      : 0x3ffc2cf0  
0x4016621e: httpd_sess_iterate at /home/xxx/components/http_server/src/httpd_sess.c:228
A2      : 0x3fad5672  A3      : 0x000000a8  A4      : 0x3ffc2ce0  A5      : 0x0000000c  
A6      : 0x00000001  A7      : 0x00000000  A8      : 0x00000000  A9      : 0x00000000  
A10     : 0xffffff2f  A11     : 0x00000000  A12     : 0x0000ffff  A13     : 0x3ffc29a0  
A14     : 0x3ffc29a0  A15     : 0x00000003  SAR     : 0x00000004  EXCCAUSE: 0x0000001c  
EXCVADDR: 0xffffff2f  LBEG    : 0x400014fd  LEND    : 0x4000150d  LCOUNT  : 0xfffffffe  
Backtrace: 0x4016621e:0x3ffc2cf0 0x40136035:0x3ffc2d10 0x401367e4:0x3ffc2d30 0x400db3cc:0x3ffc2d60 0x400d445f:0x3ffc2d80 0x400d6b8b:0x3ffc2e30
0x4016621e: httpd_sess_iterate at /home/xxx/components/http_server/src/httpd_sess.c:228
0x40136035: httpd_close_all_sessions at /home/xxx/components/http_server/src/httpd_main.c:108
0x401367e4: httpd_stop at /home/xxx/components/http_server/src/httpd_main.c:416
0x400db3cc: stop_webserver at /home/xxx/examples/xxx/main/webserver.c:1244

================= CORE DUMP START =================
UD0AABIAAABkAQAA
qL/7PzAs/D8EL/w/
UCz8P6Au/D8kCbcAPED7PzxA+z+ov/s/NED7PxQAAAB4v/s/eL/7P6i/+z8AAAAA

crash line 282

int httpd_sess_iterate(struct httpd_data *hd, int start_fd)
{
    int start_index = 0;
    int i;

    if (start_fd != -1) {
        /* Take our index to where this fd is stored */
        for (i = 0; i < hd->config.max_open_sockets; i++) {
            if (hd->hd_sd[i].fd == start_fd) {
                start_index = i + 1;
                break;
            }
        }
    }

    for (i = start_index; i < hd->config.max_open_sockets; i++) {
        if (hd->hd_sd[i].fd != -1) { // <----------crash line 228
            return hd->hd_sd[i].fd;
        }
    }
    return -1;
}

[outermanle]

@anurag-kar
I got this crash log.

I (12115192) wifi: state: run -> init (0)
I (12115192) wifi: pm stop, total sleep time: 7450312143 us / 8386439683 us
I (12115192) wifi: n:11 0, o:11 0, ap:255 255, sta:11 0, prof:1
I (12115202) wf: SYSTEM_EVENT_STA_DISCONNECTED
W (12115202) httpd_txrx: httpd_default_recv: error in recv = 113
I (12115222) wf: disconnect reason: Assoc leave(8)
I (12115252) que: ACTION_WIFI_DISCONNECTED
W (12115232) httpd_txrx: httpd_resp_send_err: 408 Request Timeout - Server closed this connection
Interface not up, skipping 0x3ffd1fb4
Interface not up, skipping 0x3ffd1fb4
W (12115282) httpd_txrx: httpd_default_send: error in send = 113
W (12115292) httpd: httpd stopping
I (12115332) wifi: n:6 0, o:11 0, ap:255 255, sta:6 0, prof:1
E (12115342) http: close socket for exception
I (12115352) http: HTTP_EVENT_DISCONNECTED
W (12115332) httpd: httpd_stop: server thread status before stopping = 1465120346
Guru Meditation Error: Core  1 panic'ed (Interrupt wdt timeout on CPU1)
Core 1 register dump:
PC      : 0x4000c271  PS      : 0x00060034  A0      : 0x8008b452  A1      : 0x3ffc2c00  
A2      : 0x3ffc1f00  A3      : 0x3f40390a  A4      : 0x00000014  A5      : 0x3ffb0bd0  
A6      : 0x3ffb0c18  A7      : 0x00000001  A8      : 0x00000001  A9      : 0x3f40390b  
A10     : 0x000000a5  A11     : 0x00000000  A12     : 0x8008bdab  A13     : 0x3ffb0ba0  
A14     : 0x00000020  A15     : 0x00000020  SAR     : 0x0000001c  EXCCAUSE: 0x00000006  
EXCVADDR: 0x00000000  LBEG    : 0x400014fd  LEND    : 0x4000150d  LCOUNT  : 0xfffffffd  
Backtrace: 0x4000c271:0x3ffc2c00 0x4008b44f:0x3ffc2c20 0x4008cc00:0x3ffc2c50 0x4008cbb6:0x00000000
0x4008b44f: vTaskSwitchContext at /home/xxx/components/freertos/tasks.c:5120
0x4008cc00: _frxt_dispatch at /home/xxx/components/freertos/portasm.S:406
0x4008cbb6: _frxt_int_exit at /home/xxx/components/freertos/portasm.S:206
Core 0 register dump:
PC      : 0x4014e374  PS      : 0x00060a34  A0      : 0x8014e588  A1      : 0x3ffc8240  
0x4014e374: SHA1Transform at /home/xxx/components/wpa_supplicant/src/crypto/sha1-internal.c:219
A2      : 0xd5417cfc  A3      : 0x67d2af6e  A4      : 0x250763c8  A5      : 0x34635acb  
A6      : 0xfc50235f  A7      : 0x594bb29f  A8      : 0x754214b4  A9      : 0x74bc8bc4  
A10     : 0x4a266f69  A11     : 0x4b58ddbc  A12     : 0x6d9e9ed4  A13     : 0x2d26d071  
A14     : 0xca62c1d6  A15     : 0x109735f7  SAR     : 0x00000002  EXCCAUSE: 0x00000006  
EXCVADDR: 0x00000000  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0x00000000  
Backtrace: 0x4014e374:0x3ffc8240 0x4014e585:0x3ffc8300 0x4014e67d:0x3ffc8320 0x4014cd3c:0x3ffc83a0 0x4014cdae:0x3ffc8460 0x4014e844:0x3ffc8490 0x40129dd5:0x3ffc8520 0x4012ad42:0x3ffc8540 0x4012ad51:0x3ffc8580 0x40118841:0x3ffc85a0 0x40118b48:0x3ffc85e0 0x401196b8:0x3ffc8620 0x401196ea:0x3ffc8670 0x401155f1:0x3ffc86c0 0x4011591c:0x3ffc8710 0x40118129:0x3ffc8730 0x4011814a:0x3ffc8750 0x40117cb4:0x3ffc8770 0x40117fce:0x3ffc8790 0x40086db8:0x3ffc87b0
0x4014e374: SHA1Transform at /home/xxx/components/wpa_supplicant/src/crypto/sha1-internal.c:219
0x4014e585: SHA1Update at /home/xxx/components/wpa_supplicant/src/crypto/sha1-internal.c:267
0x4014e67d: sha1_vector at /home/xxx/components/wpa_supplicant/src/crypto/sha1-internal.c:44 (discriminator 3)
0x4014cd3c: hmac_sha1_vector at /home/xxx/components/wpa_supplicant/src/crypto/sha1.c:80
0x4014cdae: hmac_sha1 at /home/xxx/components/wpa_supplicant/src/crypto/sha1.c:111
0x4014e844: pbkdf2_sha1_f at /home/xxx/components/wpa_supplicant/src/crypto/sha1-pbkdf2.c:54
 (inlined by) pbkdf2_sha1 at /home/xxx/components/wpa_supplicant/src/crypto/sha1-pbkdf2.c:91
0x40129dd5: wpa_set_bss at ??:?
0x4012ad42: wpa_config_bss at ??:?
0x4012ad51: wpa_sta_connect at ??:?
0x40118841: cnx_sta_connect_led_timer_cb at ??:?
0x40118b48: cnx_sta_connect_led_timer_cb at ??:?
0x401196b8: cnx_remove_all_rc at ??:?
0x401196ea: cnx_start_handoff_cb at ??:?
0x401155f1: free_bss_info at ??:?
0x4011591c: scan_inter_channel_timeout_process at ??:?
0x40118129: chm_end_op at ??:?
0x4011814a: chm_end_op_timeout_process at ??:?
0x40117cb4: wifi_station_stop at ??:?
0x40117fce: ieee80211_timer_do_process at ??:?
0x40086db8: ppTask at ??:?

================= CORE DUMP START =================
YEIAABIAAABkAQAA
XIj8PzCC/D9UiPw/
MIL8P/CH/D+Qhvw/uEH7P7hB+z9ciPw/sEH7PwEAAADEv/s/qO37P1yI/D8AAAAA
GAAAAFh6/D93aWZpAHr8P3dpZmkAxawAAAAAAFSI/D8AAAAAIQAGABcAAAABAAAA
AAAAAAAAAAAAAAAAqOj6PxDp+j946fo/AAAAAAAAAAABAAAAAAAAAJAZQD8AAAAA
SB0AQAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA

[anurag-kar]

@outermanle Looking at your previous log I suspect it is heap corruption because :

• Guru Meditation Error: Core 0 panic'ed (LoadProhibited) means the load instruction is reading from an invalid location (hd->hd_sd[i].fd at crash line 228), given by EXCVADDR: 0xffffff2f. Instead it should be within 0x3fxxxxxx - 0x6xxxxxxx
• The status flag get's overwritten, like you observed

hd is the internal httpd_data and resides on heap. Maybe some other process is writing over it. Could you check?

[outermanle]

@anurag-kar

I doubt there is heap corruption in the wifi driver.
I check all of my code and can't find any suspicious.
Or you can give me some tips to check heap corruption.

I monitor the heap size all the time, and there is no memleak, as you said it should be heap corruption issue.

And this issue only trigger when wifi disconnect event. The probability is about 1-10%.

[anurag-kar]

Refer to this for debugging heap corruption : https://docs.espressif.com/projects/esp-idf/en/latest/api-reference/system/heap_debug.html#heap-tracing-to-find-heap-corruption

[outermanle]

@anurag-kar After enable CONFIG_HEAP_POISONING_COMPREHENSIVE, this issue disappeared.
There is any update about memory issue in wifi driver recently? Specially during WIFI disconnect event.

#
 # Heap memory debugging
 #
-CONFIG_HEAP_POISONING_DISABLED=y
+CONFIG_HEAP_POISONING_DISABLED=
 CONFIG_HEAP_POISONING_LIGHT=
-CONFIG_HEAP_POISONING_COMPREHENSIVE=
+CONFIG_HEAP_POISONING_COMPREHENSIVE=y
 CONFIG_HEAP_TRACING=
+CONFIG_HEAP_TASK_TRACKING=

[anurag-kar]

@outermanle Not that I know of. Let me check with someone who would be more appropriate to answer this.

[outermanle]

Okay, Thanks.

[outermanle]

@anurag-kar
Update to the newest master branch 12b2268ee56dac79988b75dbb49a453629ed8022 and this issue still happened.

the handle passed to stop httpd is different with that one in httpd thread...

And trigger one time about watchdog in wifi driver, so stuck all the time.

@liuzfesp
I think there is true condition loop all the time in the wifi driver version 12b2268ee56dac79988b75dbb49a453629ed8022.

[anurag-kar]

the handle passed to stop httpd is different with that one in httpd thread...

@outermanle I overlooked the fact that httpd_thread has the handle stored in hd which is a local variable on the stack (though hd is pointing to http_data on the heap). Since it lies higher on the address space (stack grows high to low), it's likely that some part of the server or the URI handler is overwriting it.

Could you cross check your URI handler implementation and ensure that there is no memcpy/memset/strcpy invoked with a stack variable as destination that may be overflowing?

In the meantime I'll check the server code for any such overflows.

You can enable stack smashing check under Compiler options for detection. See https://docs.espressif.com/projects/esp-idf/en/latest/api-guides/fatal-errors.html#stack-smashing.

Could you also try increasing the stack_size in httpd_config_t structure passed to httpd_start()? I don't think it will help, but still just to be sure

httpd_config_t config = HTTPD_DEFAULT_CONFIG();
config.stack_size = 8192;

[outermanle]

Thanks @anurag-kar , I will try it.

[anurag-kar]

the handle passed to stop httpd is different with that one in httpd thread...

@outermanle Could you also tell me how you check this? Because, if that is the case, it still doesn't explain why the status value is a garbage, when accessed using the handle (valid handle) provided to httpd_stop().

[outermanle]

@anurag-kar

set 10s timeout in select @httpd thread,

and print

 I (4355902) httpd: Timeout,status(1)

stop thread

W (4346842) httpd: stopping httpd status(-1)...
W (4347842) httpd: stopping httpd status(-1)...
W (4348842) httpd: stopping httpd status(-1)...

Maybe the heap is normal, but static variable has changed by others.

In my home AP, the probability is about 40-50%.

Enable stack check but get nothing tips.

start server handle below log

I (560799) httpd: Starting httpd on port: '80'
I (560809) httpd: Started HTTP server=0x3ffd3938 on port: '80'
I (560819) httpd: Max URI handlers: '12'
I (560819) httpd: Max Stack Size: '4096'
I (560829) httpd: Registering basic handlers
I (560829) httpd: Number of handlers = 12
I (560839) httpd: Success

receive wifi disconnected and stop server handle log

W (12390139) httpd: httpd stopping handle=0x3f0b12c5
E (12390199) httpd: handle=0x3f0b12c5

so the handle has changed by others...

static httpd_handle_t httpd_server =  NULL;

[anurag-kar]

I (560799) httpd: Starting httpd on port: '80'
I (560809) httpd: Started HTTP server=0x3ffd3938 on port: '80'
I (560819) httpd: Max URI handlers: '12'
I (560819) httpd: Max Stack Size: '4096'
I (560829) httpd: Registering basic handlers
I (560829) httpd: Number of handlers = 12
I (560839) httpd: Success

@outermanle Could you tell me from which function you are printing the above?

W (12390139) httpd: httpd stopping handle=0x3f0b12c5
E (12390199) httpd: handle=0x3f0b12c5

And this?

I assume these are the httpd_start and httpd_stop functions, in which case the handle being passed to httpd_stop is wrong. The variable static httpd_handle_t httpd_server is nothing but a pointer so it shouldn't get modified by itself, unless something is changing it in the main thread.

Could you please print the value of the handle inside the event_handler, just after starting the server and just before stopping?

[outermanle]

@anurag-kar I have done your request, and get the log below.

W (561160) mst: http handle=0x3ffd3308 (print in other monitor thread every 1 seconds)
W (562160) mst: http handle=0x3ffd3308 ( monitor httpd_server value in other thread)
W (563160) mst: http handle=0x3ffd3308
W (564160) mst: http handle=0x3ffd3308
W (565160) mst: http handle=0x3ffd3308
E (565830) httpd: httpd_server: handle=0x3ffd3308, timeout=1  (print in httpd thread, it is right.)
W (566160) mst: http handle=0x3ffd3308
W (567160) mst: http handle=0x3f8f77a9  (changed!!!! and change other value after a while)
W (568160) mst: http handle=0x3f8f77a9
W (569160) mst: http handle=0x3f8f77a9
...
E (571830) httpd: httpd_server: handle=0x3ffd3308, timeout=1 (run in httpd thread, it is still right)

so I think static httpd_handle_t httpd_server = NULL; is changed by others.
And the heap is not corrupted.

[outermanle]

@anurag-kar

How can I debug global static variable change be others?

Got nothing tips when enable stack and heap debug in config file.

[anurag-kar]

@outermanle First thing, ensure that the pointer to the static handle variable, which you get as argument to the event_handler is correct.

Print the pointer to static variable in main function first :

void app_main()
{
    static httpd_handle_t server = NULL;
    ESP_LOGI(TAG, "app_main : ptr to server handle : %p", &server);

    ............................
    ............................
    ............................
}

And print the pointer to static variable in event handler :

static esp_err_t event_handler(void *ctx, system_event_t *event)
{
    httpd_handle_t *server = (httpd_handle_t *) ctx;
    ESP_LOGI(TAG, "event_handler : ptr to server handle : %p", server);

    ............................
    ............................
    ............................

    return ESP_OK;
}

Do these match?

[outermanle]

yes, they match.

but not match with the original one which store in the httpd thread.

[anurag-kar]

but not match with the original one which store in the httpd thread.

The argument to httpd_thread stores the value of handle (which is a pointer to internal struct httpd_data). So this is not a problem

Let's try moving the handle to heap:

void app_main()
{
   httpd_handle_t *server = calloc(1, sizeof(httpd_handle_t));
    ESP_LOGI(TAG, "app_main : ptr to server handle : %p", server);
    ............................
    ............................
    ............................
    initialise_wifi(server);
}

Now check if the value of handle changes in the event_handler

[outermanle]

I just move the global static static httpd_handle_t httpd_server = NULL; to another place -- in the last part of all global static variables then this issue disappear. So I think there is someone change the value around that position.

I want to catch who change the value, can you give me some tips to debug?
For I get nothing debug info though enable stack smashing check and heap corruption debug in sdkconfig file.

[negativekelvin]

You should check what other global data is placed near your variable with objdump

[igrr]

Also, if JTAG debugging is an option, try setting a watchpoint on the variable which gets corrupted. It will trigger when other code modifies it.

If you don't have access to JTAG, you can also set watchpoint from your application, calling esp_set_watchpoint function.
E.g. esp_set_watchpoint(0, &httpd_server, 4, ESP_WATCHPOINT_STORE);

The declaration of this function is in esp_panic.h.

Without JTAG connected, watchpoint will trigger a debug exception, and you will get the backtrace.

[outermanle]

@negativekelvin @igrr

I have no JTAG.
That's good suggestion, Thanks a lot!

[outermanle]

@igrr @anurag-kar @negativekelvin

Thank you very much.

Solved by add esp_set_watchpoint, The reason is array boundary exceeded.