Possible to pipe apptrace logs to GDB?

[p-rimes]

I prefer using JTAG for debugging (OpenOCD + gdb), and I would like to see the console messages inside my GDB window. I would also prefer to use apptrace/TRAX-based logging for this, and not output to the ESP32 serial port at all.

To support this (and other helpful features), I have compiled my xtensa GDB with Python support, so I can easily add new commands to my GDB, taking advantage of any Python code+libraries.

I’m wondering what would be the best way to add support for “tailing” the apptrace logs in GDB (e.g. by running a custom “esp32-apptrace” command until a breakpoint fires or I ctrl-c to stop logging). Currently I have copied the logtrace python code, and I can pretty-print apptrace logs from a recorded log file saved to disk (just a proof-of-concept python GDB command).

The next steps would be to get live streaming/“tailing” of the apptrace logs, ideally without needing a log file on disk. Would I need to patch openocd-esp32 to rework the existing apptrace commands? Is there a better way entirely?

[ESP_igrr]

Hi p-rimes, have you considered semihosting output as stdout? It should be able to reach OpenOCD console which gets mirrored in GDB.

Edit: my bad, it does get shown on OpenOCD console but not in GDB. We are refactoring semihosting support for Xtensa now to use the common (ARM) semihosting implementation in OpenOCD. Will look at fixing redirection to GDB as well.

Edit 2: there is also "GDB File I/O" which can be used to do semihosting output to GDB's stdout. Need to check if something has to be implemented to support that.

[p-rimes]

Hi @ESP_igrr,

Semihosting would be acceptable also, but in my experience (on ARM) it is quite slow (much slower than serial output, especially since I run that at 2MBaud.)

Does that slower speed limitation also apply to ESP32 semihosting?

[ESP_igrr]

Hi p-rimes,

Yes, good point about semihosting being quite slow due to the latency associated with handling the breakpoint.

Actually sending the console messages to GDB via apptrace turned out to be quite straightforward with a small patch to OpenOCD (attached). It adds a new trace destination, "con:". You can run OpenOCD with the following extra argument:
-c "init; esp32 apptrace start con:"

On the application side, you need to format and write the log messages to apptrace. Note that this is slightly different from what esp_apptrace_vprintf does. esp_apptrace_vprintf sends the pointer to the format string, along with integer values of arguments, to the host, and relies on a host-side script to do the formatting. With the proposed simple solution, you can do formatting on the target, and send the formatted strings to the host. This logic can also be wrapped in a vprintf-like function. Alternatively, you can substitute the "write" function of stdout stream — in this case all the output (coming from ESP_LOG and regular printfs) will be redirected. These strings will be displayed directly in OpenOCD window and will also be sent to GDB.

[p-rimes]

That's great! That patch is working well for me on macOS, thanks a bunch -- it's a really slick solution to do it at the OpenOCD level, and it makes the GDB part a lot easier.

I think I'd most prefer your alternative solution, overriding the stdout write function. That would actually make it useful for any prototype devices with different application versions where I don't know the exact ELF image to use. I can't quite see where to make that change though...

In the meantime I'll try to use the GDB Python support to re-use the existing apptrace/ELF-symbol-based string formatting code. That's probably a bit faster on the ESP32 side, too. Also if I'm using GDB I'll surely know the correct ELF binary, so maybe that's an OK tradeoff.

[ESP_igrr]

I think I'd most prefer your alternative solution, overriding the stdout write function. That would actually make it useful for any prototype devices with different application versions where I don't know the exact ELF image to use. I can't quite see where to make that change though...

Something like this should do:

Code: Select all

#include <stdio.h>
#include "freertos/FreeRTOS.h"
#include "freertos/task.h"
#include "esp_app_trace.h"

static int apptrace_writefn(void* cookie, const char* data, int size)
{
    int res = esp_apptrace_write(ESP_APPTRACE_DEST_TRAX, data, size, 1000);
    if (res != ESP_OK) {
        return 0;
    }
    esp_apptrace_flush(ESP_APPTRACE_DEST_TRAX, 1000);
    return size;
}

void app_main()
{
    if (!esp_apptrace_host_is_connected(ESP_APPTRACE_DEST_TRAX)) {
        printf("Waiting for JTAG connection...\n");
        while (!esp_apptrace_host_is_connected(ESP_APPTRACE_DEST_TRAX)) {
            vTaskDelay(pdMS_TO_TICKS(10));
        }
    }
    printf("JTAG connection detected\n");

    // standard IO streams are inherited when a task is created, so this needs to be done before creating other tasks:
    stdout = fwopen(NULL, &apptrace_writefn);
    // enable line buffering for this stream (to be similar to the regular UART-based output)
    static char stdout_buf[128];
    setvbuf(stdout, stdout_buf, _IOLBF, sizeof(stdout_buf));

    // now everything printed to stdout (including ESP_LOG) will be displayed in the GDB console.
}

We'll consider including something similar as a ready made solution (selectable as "Console output" option, UART0/1/2/apptrace)

One useability defect now is that you need to restart apptrace in OpenOCD when the application is restarted. I have it automated in the gdbinit script, but would be better if OpenOCD could automatically restart the trace after target reset.

[p-rimes]

Thanks for the guidance (and thanks again for the OpenOCD patch), I am really enjoying this workflow!

The output is still a bit slower than serial, but I think this could be due to the frequent flushing of TRAX. I’ll spend a bit of time tuning that; perhaps I can get away with post-mortem mode in GDB (I really only need the serial logs leading up to a breakpoint).

[ojoj42]

Hi,

I have tried the overriding stdout as in the example code above but i get a problem where I only get printouts from the task where I did the override. I was expecting the override to affect all tasks. Note that i did the override in the start of app_main which creates my other tasks.

Any idea what I am doing wrong?

Kind Regards
Daniel

[ESP_igrr]

Hi Daniel,

Sorry, I was mistaken when I said that standard streams are inherited from the parent task. This is not the case. Task creation code calls esp_reent_init (here), which sets the stdin/stdout/stderr pointers to these from the _GLOBAL_REENT structure (here).

So if you want to substitute stdout for all the new tasks, you need to overwrite _GLOBAL_REENT->stdout.

[ojoj42]

Hi ESP_igrr,

Thank you for your fast replay, Now it works.

I think _GLOBAL_REENT->stdout should be _GLOBAL_REENT->_stdout by the way.

Thanks again

Kind Regards
Daniel