GDB debugging commands do the wrong thing (IDFGH-6406) #8065

szekelyisz · 2021-12-12T02:53:49Z

Environment

Development Kit: ESP32-Ethernet-Kit
Kit version (for WroverKit/PicoKit/DevKitC): 1.1
Module or chip used: ESP32-WROVER-B
IDF version (run git describe --tags to find it): v4.4-beta1-177-ge104dd7f27
Build System: idf.py
Compiler version (run xtensa-esp32-elf-gcc --version to find it): xtensa-esp32-elf-gcc (crosstool-NG esp-2021r2) 8.4.0
Operating System: Linux
Using an IDE?: Eclipse
Power Supply: USB

Problem Description

Stepping commands seem to be messed up. After a breakpoint is hit, "Step over" does "Step into" for example. This is not an Eclipse plugin problem as it also happens if I use the debugger console to give direct commands to gdb.

Expected Behavior

Stepping functions to work as expected.

Actual Behavior

"Step over" does "Step into" and other weird stuff like seemingly corrupting the stack.

Steps to reproduce

Compile the protocols/http_server/simple example.
Start a JTAG debugging session.
Set a breakpoint at this line
Perform an HTTP request that should cause the breakpoint to be hit.
Try stepping around. See below for a full session transcript.

Code to reproduce this issue

Here

Debug Logs

GNU gdb (crosstool-NG esp-2021r2) 9.2.90.20200913-git
Copyright (C) 2020 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "--host=x86_64-build_pc-linux-gnu --target=xtensa-esp32-elf".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word".
Note: automatically using hardware breakpoints for read-only addresses.
[New Thread 1073460088]
[New Thread 1073458200]
[New Thread 1073448924]
[New Thread 1073453372]
[New Thread 1073413676]
[New Thread 1073411944]
[Switching to Thread 1073457852]

Thread 1 hit Temporary breakpoint 2, app_main () at ../main/main.c:394
394	{
[New Thread 1073510944]
[New Thread 1073466700]
[New Thread 1073479988]
[New Thread 1073470760]
[Switching to Thread 1073510944]

Thread 8 hit Breakpoint 1, hello_get_handler (req=0x3ffc5f74) at ../main/main.c:156
156	    buf_len = httpd_req_get_hdr_value_len(req, "Host") + 1;
[Switching to thread 8 (Thread 1073510944)]
#0  hello_get_handler (req=0x3ffc5f74) at ../main/main.c:156
156	    buf_len = httpd_req_get_hdr_value_len(req, "Host") + 1;
[Switching to thread 8 (Thread 1073510944)]
#0  hello_get_handler (req=0x3ffc5f74) at ../main/main.c:156
156	    buf_len = httpd_req_get_hdr_value_len(req, "Host") + 1;

We hit the breakpoint. Let's take a look at our backtrace:

bt full
#0  hello_get_handler (req=0x3ffc5f74) at ../main/main.c:156
        buf = <optimized out>
        buf_len = <optimized out>
        resp_str = <optimized out>
#1  0x400f8256 in httpd_uri (hd=0x3ffc5f18) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_uri.c:329
        uri = <optimized out>
        req = 0x3ffc5f74
        res = 0x3ffc63bc
        err = HTTPD_500_INTERNAL_SERVER_ERROR
        __func__ = "httpd_uri"
#2  0x400f6fc4 in httpd_parse_req (hd=0x3ffc5f18) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_parse.c:659
        r = 0x3ffc5f74
        blk_len = <optimized out>
        offset = 0
        parser = {type = 0, flags = 0, state = 21, header_state = 0, index = 0, lenient_http_headers = 0, nread = 0, content_length = 18446744073709551615, http_major = 1, http_minor = 1, status_code = 0, method = 1, http_errno = 31, upgrade = 0, data = 0x3ffc7830}
        parser_data = {settings = {on_message_begin = 0x0, on_url = 0x400f69c0 <cb_url>, on_status = 0x0, on_header_field = 0x400f6d5c <cb_header_field>, on_header_value = 0x400f695c <cb_header_value>, on_headers_complete = 0x400f6b14 <cb_headers_complete>, on_body = 0x400f6d04 <cb_on_body>, on_message_complete = 0x400f6c94 <cb_no_body>, on_chunk_header = 0x0, on_chunk_complete = 0x0}, req = 0x3ffc5f74, status = PARSING_COMPLETE, error = HTTPD_500_INTERNAL_SERVER_ERROR, last = {at = 0x0, length = 0}, paused = true, pre_parsed = 0, raw_datalen = 61}
        __func__ = <optimized out>
#3  0x400f7063 in httpd_req_new (hd=0x3ffc5f18, sd=<optimized out>) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_parse.c:784
        r = 0x3ffc5f74
        ra = 0x3ffc6198
        ret = <optimized out>
#4  0x400f7751 in httpd_sess_process (hd=0x3ffc5f18, session=0x3ffc63f4) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_sess.c:412
        __func__ = <optimized out>
#5  0x400f6181 in httpd_process_session (session=0x3ffc63f4, context=0x3ffc793c) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_main.c:178
        ctx = 0x3ffc793c
        fd = <optimized out>
        __func__ = <optimized out>
#6  0x40143572 in httpd_sess_enum (hd=<optimized out>, enum_function=0x400f6130 <httpd_process_session>, context=0x3ffc793c) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_sess.c:50
        current = 0x3ffc63f4
        end = 0x3ffc6844
#7  0x400f63be in httpd_server (hd=0x3ffc5f18) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_main.c:228
        read_set = {fds_bits = {0, 33554432}}
        tmp_max_fd = 57
        maxfd = <optimized out>
        __func__ = "httpd_server"
        active_cnt = <optimized out>
        context = {fdset = 0x3ffc7930, hd = 0x3ffc5f18}
#8  0x400f6422 in httpd_thread (arg=0x3ffc5f18) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_main.c:250
        ret = <optimized out>
        hd = 0x3ffc5f18
        __func__ = <optimized out>
#9  0x4008b4b4 in vPortTaskWrapper (pxCode=0x400f6414 <httpd_thread>, pvParameters=0x3ffc5f18) at /home/szabi/esp/esp-idf/components/freertos/port/xtensa/port.c:130
        pcTaskName = <optimized out>

Seems fair. Let's do a "Step over". We expect to go to line 157 but we end up somewhere else:

n
httpd_req_get_hdr_value_len (r=0x3ffc5f74, field=0x0) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_parse.c:954
954	{

That is an equivalent of a "Step into" operation. Let's see where we are exactly:

bt full
#0  httpd_req_get_hdr_value_len (r=0x3ffc5f74, field=0x0) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_parse.c:954
        ra = <optimized out>
        hdr_ptr = <optimized out>
        count = <optimized out>
#1  0x400f8256 in httpd_uri (hd=0x3ffc5f18) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_uri.c:329
        uri = <optimized out>
        req = 0x3ffc5f74
        res = 0x3ffc63bc
        err = HTTPD_500_INTERNAL_SERVER_ERROR
        __func__ = "httpd_uri"
#2  0x400f6fc4 in httpd_parse_req (hd=0x3ffc5f18) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_parse.c:659
        r = 0x3ffc5f74
        blk_len = <optimized out>
        offset = 0
        parser = {type = 0, flags = 0, state = 21, header_state = 0, index = 0, lenient_http_headers = 0, nread = 0, content_length = 18446744073709551615, http_major = 1, http_minor = 1, status_code = 0, method = 1, http_errno = 31, upgrade = 0, data = 0x3ffc7830}
        parser_data = {settings = {on_message_begin = 0x0, on_url = 0x400f69c0 <cb_url>, on_status = 0x0, on_header_field = 0x400f6d5c <cb_header_field>, on_header_value = 0x400f695c <cb_header_value>, on_headers_complete = 0x400f6b14 <cb_headers_complete>, on_body = 0x400f6d04 <cb_on_body>, on_message_complete = 0x400f6c94 <cb_no_body>, on_chunk_header = 0x0, on_chunk_complete = 0x0}, req = 0x3ffc5f74, status = PARSING_COMPLETE, error = HTTPD_500_INTERNAL_SERVER_ERROR, last = {at = 0x0, length = 0}, paused = true, pre_parsed = 0, raw_datalen = 61}
        __func__ = <optimized out>
#3  0x400f7063 in httpd_req_new (hd=0x3ffc5f18, sd=<optimized out>) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_parse.c:784
        r = 0x3ffc5f74
        ra = 0x3ffc6198
        ret = <optimized out>
#4  0x400f7751 in httpd_sess_process (hd=0x3ffc5f18, session=0x3ffc63f4) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_sess.c:412
        __func__ = <optimized out>
#5  0x400f6181 in httpd_process_session (session=0x3ffc63f4, context=0x3ffc793c) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_main.c:178
        ctx = 0x3ffc793c
        fd = <optimized out>
        __func__ = <optimized out>
#6  0x40143572 in httpd_sess_enum (hd=<optimized out>, enum_function=0x400f6130 <httpd_process_session>, context=0x3ffc793c) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_sess.c:50
        current = 0x3ffc63f4
        end = 0x3ffc6844
#7  0x400f63be in httpd_server (hd=0x3ffc5f18) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_main.c:228
        read_set = {fds_bits = {0, 33554432}}
        tmp_max_fd = 57
        maxfd = <optimized out>
        __func__ = "httpd_server"
        active_cnt = <optimized out>
        context = {fdset = 0x3ffc7930, hd = 0x3ffc5f18}
#8  0x400f6422 in httpd_thread (arg=0x3ffc5f18) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_main.c:250
        ret = <optimized out>
        hd = 0x3ffc5f18
        __func__ = <optimized out>
#9  0x4008b4b4 in vPortTaskWrapper (pxCode=0x400f6414 <httpd_thread>, pvParameters=0x3ffc5f18) at /home/szabi/esp/esp-idf/components/freertos/port/xtensa/port.c:130
        pcTaskName = <optimized out>

We seem to have lost hello_get_handler's stack frame. But let's keep going:

n
httpd_req_get_hdr_value_len (r=0x3ffc5f74, field=0x3f403410 "Host") at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_parse.c:955
955	    if (r == NULL || field == NULL) {
n
963	    struct httpd_req_aux *ra = r->aux;
n
964	    const char   *hdr_ptr = ra->scratch;         /*!< Request headers are kept in scratch buffer */
n
965	    unsigned      count   = ra->req_hdrs_count;  /*!< Count set during parsing  */
n
967	    while (count--) {
n
971	        const char *val_ptr = strchr(hdr_ptr, ':');
n
972	        if (!val_ptr) {
n
980	        if ((val_ptr - hdr_ptr != strlen(field)) ||
n
0x40001550 in ?? ()

At this point we're in ROM code. The last executed call was strlen. But also hello_get_handler is back on the stack, and now httpd_req_get_hdr_value_len is gone:

bt full
#0  0x40001550 in ?? ()
No symbol table info available.
#1  0x400d6a33 in hello_get_handler (req=0x3ffc5f74) at ../main/main.c:156
        buf = <optimized out>
        buf_len = <optimized out>
        resp_str = <optimized out>
#2  0x400f8256 in httpd_uri (hd=0x3ffc5f18) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_uri.c:329
        uri = <optimized out>
        req = 0x3ffc5f74
        res = 0x3ffc63bc
        err = HTTPD_500_INTERNAL_SERVER_ERROR
        __func__ = "httpd_uri"
#3  0x400f6fc4 in httpd_parse_req (hd=0x3ffc5f18) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_parse.c:659
        r = 0x3ffc5f74
        blk_len = <optimized out>
        offset = 0
        parser = {type = 0, flags = 0, state = 21, header_state = 0, index = 0, lenient_http_headers = 0, nread = 0, content_length = 18446744073709551615, http_major = 1, http_minor = 1, status_code = 0, method = 1, http_errno = 31, upgrade = 0, data = 0x3ffc7830}
        parser_data = {settings = {on_message_begin = 0x0, on_url = 0x400f69c0 <cb_url>, on_status = 0x0, on_header_field = 0x400f6d5c <cb_header_field>, on_header_value = 0x400f695c <cb_header_value>, on_headers_complete = 0x400f6b14 <cb_headers_complete>, on_body = 0x400f6d04 <cb_on_body>, on_message_complete = 0x400f6c94 <cb_no_body>, on_chunk_header = 0x0, on_chunk_complete = 0x0}, req = 0x3ffc5f74, status = PARSING_COMPLETE, error = HTTPD_500_INTERNAL_SERVER_ERROR, last = {at = 0x0, length = 0}, paused = true, pre_parsed = 0, raw_datalen = 61}
        __func__ = <optimized out>
#4  0x400f7063 in httpd_req_new (hd=0x3ffc5f18, sd=<optimized out>) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_parse.c:784
        r = 0x3ffc5f74
        ra = 0x3ffc6198
        ret = <optimized out>
#5  0x400f7751 in httpd_sess_process (hd=0x3ffc5f18, session=0x3ffc63f4) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_sess.c:412
        __func__ = <optimized out>
#6  0x400f6181 in httpd_process_session (session=0x3ffc63f4, context=0x3ffc793c) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_main.c:178
        ctx = 0x3ffc793c
        fd = <optimized out>
        __func__ = <optimized out>
#7  0x40143572 in httpd_sess_enum (hd=<optimized out>, enum_function=0x400f6130 <httpd_process_session>, context=0x3ffc793c) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_sess.c:50
        current = 0x3ffc63f4
        end = 0x3ffc6844
#8  0x400f63be in httpd_server (hd=0x3ffc5f18) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_main.c:228
        read_set = {fds_bits = {0, 33554432}}
        tmp_max_fd = 57
        maxfd = <optimized out>
        __func__ = "httpd_server"
        active_cnt = <optimized out>
        context = {fdset = 0x3ffc7930, hd = 0x3ffc5f18}
#9  0x400f6422 in httpd_thread (arg=0x3ffc5f18) at /home/szabi/esp/esp-idf/components/esp_http_server/src/httpd_main.c:250
        ret = <optimized out>
        hd = 0x3ffc5f18
        __func__ = <optimized out>
#10 0x4008b4b4 in vPortTaskWrapper (pxCode=0x400f6414 <httpd_thread>, pvParameters=0x3ffc5f18) at /home/szabi/esp/esp-idf/components/freertos/port/xtensa/port.c:130
        pcTaskName = <optimized out>

If you just let it run, the example will work as expected, so my guess is that it's not actually corrupting the stack, just hides the 2nd frame from the top for some reason.

Other items if possible

simple.elf.gz

The text was updated successfully, but these errors were encountered:

MPC-BlackBox · 2022-02-03T11:11:00Z

I have had the same problem. I found that this is caused by esp-2021r2-8.4.0 If you reinstall esp-idf version 4.3.1 and install the tools,
git clone -b v4.3.1 --recursive https://github.com/espressif/esp-idf.git esp-idf-v4.3.1
cd esp-idf-v4.3.1/tools
python idf_tools.py install

this will install the old GBD into your ~/.espressif directory
.espressif/tools/xtensa-esp32-elf/esp-2021r1-8.4.0/xtensa-esp32-elf/bin/xtensa-esp32-elf-gdb

In eclipse set the GDB client to this old GDB version.

igrr · 2022-02-08T15:13:19Z

@szekelyisz @MPC-BlackBox Thank you for the issue report. We were able to confirm the issue. It is a regression introduced while fixing another bug (interrupted backtraces in "noreturn" functions, such as "abort".)
We will make a new release to fix the issue.

gerekon · 2022-02-08T20:00:05Z

Sorry, closed it accidentally instead of its duplicate in OpenOCD repo.

Closes #8065 Closes #8342 Closes espressif/openocd-esp32#210

szekelyisz · 2022-10-20T23:26:48Z

I'm still experiencing this problem with toolchain version 2022r1.

szekelyisz · 2022-10-23T14:20:43Z

@igrr Can you reopen this issue please?

Lapshin · 2022-10-23T14:39:26Z

@szekelyisz , could you show the version? Please run xtensa-esp32-elf-gdb --version

szekelyisz · 2022-10-23T14:47:13Z

@szekelyisz , could you show the version? Please run xtensa-esp32-elf-gdb --version

$ xtensa-esp32-elf-gdb --version
GNU gdb (esp-gdb) 11.2_20220823

Lapshin · 2022-10-23T15:12:17Z

@szekelyisz , this version must contain the fix...

Could you please describe steps to reproduce?

szekelyisz · 2022-10-23T15:32:10Z

@szekelyisz , this version must contain the fix...

Could you please describe steps to reproduce?

Thanks for dealing with this @Lapshin . Please see the original report for detailed instructions to reproduce.

Lapshin · 2022-10-26T15:04:19Z

@szekelyisz , sorry for the long delay!

The issue was fixed on GDB side but did not fix on OpenOCD side.

Today it should be released. The tag for it is already created but artifacts have not been uploaded yet.

After the release, IDF will be updated with the newest OpenOCD in a few days.

szekelyisz · 2022-10-26T18:02:58Z

Thank you @Lapshin. I'll wait for the release and test it.

gerekon · 2022-10-28T10:07:27Z

@szekelyisz Release is ready https://github.com/espressif/openocd-esp32/releases/tag/v0.11.0-esp32-20221026

Lapshin · 2022-11-12T11:01:56Z

@szekelyisz does it work for your case now?

szekelyisz · 2022-11-22T18:40:40Z

Sorry for the long delay @Lapshin. It seems to work fine. Thanks for your help.

espressif-bot added the Status: Opened Issue is new label Dec 12, 2021

github-actions bot changed the title ~~GDB debugging commands do the wrong thing~~ GDB debugging commands do the wrong thing (IDFGH-6406) Dec 12, 2021

MPC-BlackBox mentioned this issue Feb 3, 2022

Problem with xtensa-esp32-elf-gdb version esp-2021r2-8.4.0 debug step command not working correctly (IDFGH-6713) #8342

Closed

gerekon mentioned this issue Feb 8, 2022

OpenOCD V11 IDF V4.4 Eclipse Debugger steps into when using stepover command. (OCD-478) espressif/openocd-esp32#210

Closed

gerekon closed this as completed Feb 8, 2022

gerekon reopened this Feb 8, 2022

igrr mentioned this issue Feb 11, 2022

backtrace for abort / panic not available in coredump (IDFGH-4276) #6124

Closed

espressif-bot closed this as completed in d25c5b8 Feb 23, 2022

espressif-bot pushed a commit that referenced this issue Mar 3, 2022

tools: update esp-2021r2-patch3 toolchain for fixing GDB

1982883

Closes #8065 Closes #8342 Closes espressif/openocd-esp32#210

espressif-bot pushed a commit that referenced this issue Mar 8, 2022

tools: update esp-2021r2-patch3 toolchain for fixing GDB

115663d

Closes #8065 Closes #8342 Closes espressif/openocd-esp32#210

espressif-bot added Resolution: Done Issue is done internally Status: Done Issue is done internally and removed Status: Opened Issue is new labels May 6, 2022

espressif-bot added Status: In Progress Work is in progress and removed Resolution: Done Issue is done internally Status: Done Issue is done internally labels Oct 23, 2022

espressif-bot assigned Lapshin Oct 23, 2022

espressif-bot added Resolution: Done Issue is done internally Status: Done Issue is done internally and removed Status: In Progress Work is in progress labels Nov 23, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

GDB debugging commands do the wrong thing (IDFGH-6406) #8065

GDB debugging commands do the wrong thing (IDFGH-6406) #8065

szekelyisz commented Dec 12, 2021 •

edited

MPC-BlackBox commented Feb 3, 2022 •

edited

igrr commented Feb 8, 2022

gerekon commented Feb 8, 2022

szekelyisz commented Oct 20, 2022

szekelyisz commented Oct 23, 2022

Lapshin commented Oct 23, 2022

szekelyisz commented Oct 23, 2022

Lapshin commented Oct 23, 2022

szekelyisz commented Oct 23, 2022

Lapshin commented Oct 26, 2022

szekelyisz commented Oct 26, 2022

gerekon commented Oct 28, 2022

Lapshin commented Nov 12, 2022

szekelyisz commented Nov 22, 2022

GDB debugging commands do the wrong thing (IDFGH-6406) #8065

GDB debugging commands do the wrong thing (IDFGH-6406) #8065

Comments

szekelyisz commented Dec 12, 2021 • edited

Environment

Problem Description

Expected Behavior

Actual Behavior

Steps to reproduce

Code to reproduce this issue

Debug Logs

Other items if possible

MPC-BlackBox commented Feb 3, 2022 • edited

igrr commented Feb 8, 2022

gerekon commented Feb 8, 2022

szekelyisz commented Oct 20, 2022

szekelyisz commented Oct 23, 2022

Lapshin commented Oct 23, 2022

szekelyisz commented Oct 23, 2022

Lapshin commented Oct 23, 2022

szekelyisz commented Oct 23, 2022

Lapshin commented Oct 26, 2022

szekelyisz commented Oct 26, 2022

gerekon commented Oct 28, 2022

Lapshin commented Nov 12, 2022

szekelyisz commented Nov 22, 2022

szekelyisz commented Dec 12, 2021 •

edited

MPC-BlackBox commented Feb 3, 2022 •

edited