esp32_sysview.c

Go to the documentation of this file.

// SPDX-License-Identifier: GPL-2.0-or-later
 
/***************************************************************************
 *   ESP32 sysview tracing module                                          *
 *   Copyright (C) 2020 Espressif Systems Ltd.                             *
 ***************************************************************************/
 
#ifdef HAVE_CONFIG_H
#include "config.h"
#endif
 
#include <helper/log.h>
#include "esp32_apptrace.h"
#include "esp32_sysview.h"
#include "segger_sysview.h"
 
/* in SystemView mode core ID is passed in event ID field */
#define ESP32_SYSVIEW_USER_BLOCK_CORE(_v_)  (0) /* not used */
#define ESP32_SYSVIEW_USER_BLOCK_LEN(_v_)   (_v_)
#define ESP32_SYSVIEW_USER_BLOCK_HDR_SZ     2
 
struct esp_sysview_target2host_hdr {
    uint8_t block_sz;
    uint8_t wr_sz;
};
#define SYSVIEW_BLOCK_SIZE_OFFSET       0
#define SYSVIEW_WR_SIZE_OFFSET          1
 
static int esp_sysview_trace_header_write(struct esp32_apptrace_cmd_ctx *ctx, bool mcore_format);
static int esp32_sysview_core_id_get(struct target *target, uint8_t *hdr_buf);
static uint32_t esp32_sysview_usr_block_len_get(struct target *target, uint8_t *hdr_buf, uint32_t *wr_len);
 
int esp32_sysview_cmd_init(struct esp32_apptrace_cmd_ctx *cmd_ctx,
    struct command_invocation *cmd,
    int mode,
    bool mcore_format,
    const char **argv,
    int argc)
{
    struct esp32_sysview_cmd_data *cmd_data;
 
    if (argc < 1) {
        command_print(cmd, "Not enough args! Need trace data destination!");
        return ERROR_FAIL;
    }
 
    int res = esp32_apptrace_cmd_ctx_init(cmd_ctx, cmd, mode);
    if (res != ERROR_OK)
        return res;
 
    int core_num = cmd_ctx->cores_num;
 
    if (!mcore_format && argc < core_num) {
        command_print(cmd, "Not enough args! Need %d trace data destinations!", core_num);
        res = ERROR_FAIL;
        goto on_error;
    }
 
    cmd_data = calloc(1, sizeof(*cmd_data));
    if (!cmd_data) {
        command_print(cmd, "No memory for command data!");
        res = ERROR_FAIL;
        goto on_error;
    }
    cmd_ctx->cmd_priv = cmd_data;
    cmd_data->mcore_format = mcore_format;
 
    /*outfile1 [outfile2] [poll_period [trace_size [stop_tmo [wait4halt [skip_size]]]]] */
    int dests_num = esp32_apptrace_dest_init(cmd_data->data_dests, argv, !mcore_format ? core_num : 1);
    if (!mcore_format && dests_num < core_num) {
        command_print(cmd, "Not enough args! Need %d trace data destinations!", core_num);
        free(cmd_data);
        res = ERROR_FAIL;
        goto on_error;
    }
    cmd_data->apptrace.max_len = UINT32_MAX;
    cmd_data->apptrace.poll_period = 0 /*ms*/;
    cmd_ctx->stop_tmo = -1.0;   /* infinite */
    if (argc > dests_num) {
        /* parse remaining args */
        esp32_apptrace_cmd_args_parse(cmd_ctx,
            &cmd_data->apptrace,
            &argv[dests_num],
            argc - dests_num);
    }
    LOG_USER("App trace params: from %d cores, size %u bytes, stop_tmo %g s, "
        "poll period %u ms, wait_rst %d, skip %u bytes",
        cmd_ctx->cores_num,
        cmd_data->apptrace.max_len,
        cmd_ctx->stop_tmo,
        cmd_data->apptrace.poll_period,
        cmd_data->apptrace.wait4halt,
        cmd_data->apptrace.skip_len);
 
    cmd_ctx->trace_format.hdr_sz = ESP32_SYSVIEW_USER_BLOCK_HDR_SZ;
    cmd_ctx->trace_format.core_id_get = esp32_sysview_core_id_get;
    cmd_ctx->trace_format.usr_block_len_get = esp32_sysview_usr_block_len_get;
 
    res = esp_sysview_trace_header_write(cmd_ctx, mcore_format);
    if (res != ERROR_OK) {
        command_print(cmd, "Failed to write trace header (%d)!", res);
        esp32_apptrace_dest_cleanup(cmd_data->data_dests, core_num);
        free(cmd_data);
        return res;
    }
    return ERROR_OK;
on_error:
    cmd_ctx->running = 0;
    esp32_apptrace_cmd_ctx_cleanup(cmd_ctx);
    return res;
}
 
int esp32_sysview_cmd_cleanup(struct esp32_apptrace_cmd_ctx *cmd_ctx)
{
    struct esp32_sysview_cmd_data *cmd_data = cmd_ctx->cmd_priv;
 
    esp32_apptrace_dest_cleanup(cmd_data->data_dests, cmd_ctx->cores_num);
    free(cmd_data);
    cmd_ctx->cmd_priv = NULL;
    esp32_apptrace_cmd_ctx_cleanup(cmd_ctx);
    return ERROR_OK;
}
 
static int esp32_sysview_core_id_get(struct target *target, uint8_t *hdr_buf)
{
    /* for sysview compressed apptrace header is used, so core id is encoded in sysview packet */
    return 0;
}
 
static uint32_t esp32_sysview_usr_block_len_get(struct target *target, uint8_t *hdr_buf, uint32_t *wr_len)
{
    *wr_len = ESP32_SYSVIEW_USER_BLOCK_LEN(hdr_buf[SYSVIEW_WR_SIZE_OFFSET]);
    return ESP32_SYSVIEW_USER_BLOCK_LEN(hdr_buf[SYSVIEW_BLOCK_SIZE_OFFSET]);
}
 
static int esp_sysview_trace_header_write(struct esp32_apptrace_cmd_ctx *ctx, bool mcore_format)
{
    struct esp32_sysview_cmd_data *cmd_data = ctx->cmd_priv;
    char *hdr_str;
    int dests_num;
 
    if (!mcore_format) {
        hdr_str = ";\n"
            "; Version     " SYSVIEW_MIN_VER_STRING "\n"
            "; Author      Espressif Inc\n"
            ";\n";
        dests_num = ctx->cores_num;
    } else {
        hdr_str = ";\n"
            "; Version     " SYSVIEW_MIN_VER_STRING "\n"
            "; Author      Espressif Inc\n"
            "; ESP_Extension\n"
            ";\n";
        dests_num = 1;
    }
 
    int hdr_len = strlen(hdr_str);
    for (int i = 0; i < dests_num; i++) {
        int res = cmd_data->data_dests[i].write(cmd_data->data_dests[i].priv,
            (uint8_t *)hdr_str,
            hdr_len);
        if (res != ERROR_OK) {
            LOG_ERROR("sysview: Failed to write %u bytes to dest %d!", hdr_len, i);
            return ERROR_FAIL;
        }
    }
    return ERROR_OK;
}
 
static void sysview_encode_u32(uint8_t **dest, uint32_t val)
{
    uint8_t *sv_ptr = *dest;
    while (val > 0x7F) {
        *sv_ptr++ = (uint8_t)(val | 0x80);
        val >>= 7;
    }
    *sv_ptr++ = (uint8_t)val;
    *dest = sv_ptr;
}
 
static uint32_t esp_sysview_decode_u32(uint8_t **ptr)
{
    uint32_t val = 0;
    for (int k = 0;; k++, (*ptr)++) {
        if (**ptr & 0x80) {
            val |= (uint32_t)(**ptr & ~0x80) << 7 * k;
        } else {
            val |= (uint32_t)**ptr << 7 * k;
            (*ptr)++;
            break;
        }
    }
    return val;
}
 
static uint16_t esp_sysview_decode_plen(uint8_t **ptr)
{
    uint16_t payload_len = 0;
    uint8_t *p = *ptr;
    /* here pkt points to encoded payload length */
    if (*p & 0x80) {
        payload_len = *(p + 1); /* higher part */
        payload_len = (payload_len << 7) | (*p & ~0x80);/* lower 7 bits */
        p += 2; /* payload len (2 bytes) */
    } else {
        payload_len = *p;
        p++;    /* payload len (1 byte) */
    }
    *ptr = p;
 
    return payload_len;
}
 
static uint16_t esp_sysview_get_predef_payload_len(uint16_t id, uint8_t *pkt)
{
    uint16_t len;
    uint8_t *ptr = pkt;
 
    switch (id) {
    case SYSVIEW_EVTID_OVERFLOW:
    case SYSVIEW_EVTID_ISR_ENTER:
    case SYSVIEW_EVTID_TASK_START_EXEC:
    case SYSVIEW_EVTID_TASK_START_READY:
    case SYSVIEW_EVTID_TASK_CREATE:
    case SYSVIEW_EVTID_SYSTIME_CYCLES:
    case SYSVIEW_EVTID_USER_START:
    case SYSVIEW_EVTID_USER_STOP:
    case SYSVIEW_EVTID_TIMER_ENTER:
        /*ENCODE_U32 */
        esp_sysview_decode_u32(&ptr);
        len = ptr - pkt;
        break;
    case SYSVIEW_EVTID_TASK_STOP_READY:
    case SYSVIEW_EVTID_SYSTIME_US:
        /*2*ENCODE_U32 */
        esp_sysview_decode_u32(&ptr);
        esp_sysview_decode_u32(&ptr);
        len = ptr - pkt;
        break;
    case SYSVIEW_EVTID_SYSDESC:
        /*str(128 + 1) */
        len = *ptr + 1;
        break;
    case SYSVIEW_EVTID_TASK_INFO:
    case SYSVIEW_EVTID_MODULEDESC:
        /*2*ENCODE_U32 + str */
        esp_sysview_decode_u32(&ptr);
        esp_sysview_decode_u32(&ptr);
        /* TODO: add support for strings longer then 255 bytes */
        len = ptr - pkt + *ptr + 1;
        break;
    case SYSVIEW_EVTID_STACK_INFO:
        /*4*ENCODE_U32 */
        esp_sysview_decode_u32(&ptr);
        esp_sysview_decode_u32(&ptr);
        esp_sysview_decode_u32(&ptr);
        esp_sysview_decode_u32(&ptr);
        len = ptr - pkt;
        break;
    case SYSVIEW_EVTID_ISR_EXIT:
    case SYSVIEW_EVTID_TASK_STOP_EXEC:
    case SYSVIEW_EVTID_TRACE_START:
    case SYSVIEW_EVTID_TRACE_STOP:
    case SYSVIEW_EVTID_IDLE:
    case SYSVIEW_EVTID_ISR_TO_SCHEDULER:
    case SYSVIEW_EVTID_TIMER_EXIT:
        len = 0;
        break;
 
    /*case SYSVIEW_EVTID_NOP: */
    default:
        LOG_ERROR("sysview: Unsupported predef event %d!", id);
        len = 0;
    }
    return len;
}
 
static uint16_t esp_sysview_parse_packet(uint8_t *pkt_buf,
    uint32_t *pkt_len,
    unsigned int *pkt_core_id,
    uint32_t *delta,
    uint32_t *delta_len,
    bool clear_core_bit)
{
    uint8_t *pkt = pkt_buf;
    uint16_t event_id = 0, payload_len = 0;
 
    *pkt_core_id = 0;
    *pkt_len = 0;
    /* 1-2 byte of message type, 0-2  byte of payload length, payload, 1-5 bytes of timestamp. */
    if (*pkt & 0x80) {
        if (*(pkt + 1) & (1 << 6)) {
            if (clear_core_bit)
                *(pkt + 1) &= ~(1 << 6);    /* clear core_id bit */
            *pkt_core_id = 1;
        }
        event_id = *(pkt + 1) & ~(1 << 6);  /* higher part */
        event_id = (event_id << 7) | (*pkt & ~0x80);    /* lower 7 bits */
        pkt += 2;   /* event_id (2 bytes) */
        /* here pkt points to encoded payload length */
        payload_len = esp_sysview_decode_plen(&pkt);
    } else {
        if (*pkt & (1 << 6)) {
            if (clear_core_bit)
                *pkt &= ~(1 << 6);  /* clear core_id bit */
            *pkt_core_id = 1;
        }
        /* event_id (1 byte) */
        event_id = *pkt & ~(1 << 6);
        pkt++;
        if (event_id < 24)
            payload_len = esp_sysview_get_predef_payload_len(event_id, pkt);
        else
            payload_len = esp_sysview_decode_plen(&pkt);
    }
    pkt += payload_len;
    uint8_t *delta_start = pkt;
    *delta = esp_sysview_decode_u32(&pkt);
    *delta_len = pkt - delta_start;
    *pkt_len = pkt - pkt_buf;
    LOG_DEBUG("sysview: evt %d len %d plen %d dlen %d",
        event_id,
        *pkt_len,
        payload_len,
        *delta_len);
    return event_id;
}
 
static int esp32_sysview_write_packet(struct esp32_sysview_cmd_data *cmd_data,
    int pkt_core_id, uint32_t pkt_len, uint8_t *pkt_buf, uint32_t delta_len, uint8_t *delta_buf)
{
    if (!cmd_data->data_dests[pkt_core_id].write)
        return ERROR_FAIL;
 
    int res = cmd_data->data_dests[pkt_core_id].write(cmd_data->data_dests[pkt_core_id].priv, pkt_buf, pkt_len);
 
    if (res != ERROR_OK) {
        LOG_ERROR("sysview: Failed to write %u bytes to dest %d!", pkt_len, pkt_core_id);
        return res;
    }
    if (delta_len) {
        /* write packet with modified delta */
        res = cmd_data->data_dests[pkt_core_id].write(cmd_data->data_dests[pkt_core_id].priv, delta_buf, delta_len);
        if (res != ERROR_OK) {
            LOG_ERROR("sysview: Failed to write %u bytes of delta to dest %d!", delta_len, pkt_core_id);
            return res;
        }
    }
    return ERROR_OK;
}
 
static int esp32_sysview_process_packet(struct esp32_apptrace_cmd_ctx *ctx,
    unsigned int pkt_core_id, uint16_t event_id, uint32_t delta, uint32_t delta_len,
    uint32_t pkt_len, uint8_t *pkt_buf)
{
    struct esp32_sysview_cmd_data *cmd_data = ctx->cmd_priv;
    int pkt_core_changed = 0;
    uint32_t new_delta_len = 0;
    uint8_t new_delta_buf[10];
    uint32_t wr_len = pkt_len;
 
    if (ctx->cores_num > 1) {
        if (cmd_data->sv_last_core_id == pkt_core_id) {
            /* if this packet is for the same core as the prev one acc delta and write packet unmodified */
            cmd_data->sv_acc_time_delta += delta;
        } else {
            /* if this packet is for another core then prev one set acc delta to the packet's delta */
            uint8_t *delta_ptr = new_delta_buf;
            sysview_encode_u32(&delta_ptr, delta + cmd_data->sv_acc_time_delta);
            cmd_data->sv_acc_time_delta = delta;
            wr_len -= delta_len;
            new_delta_len = delta_ptr - new_delta_buf;
            pkt_core_changed = 1;
        }
        cmd_data->sv_last_core_id = pkt_core_id;
    }
    if (pkt_core_id >= ctx->cores_num) {
        LOG_WARNING("sysview: invalid core ID in packet %d, must be less then %d! Event id %d",
            pkt_core_id,
            ctx->cores_num,
            event_id);
        return ERROR_FAIL;
    }
    int res = esp32_sysview_write_packet(cmd_data,
        pkt_core_id,
        wr_len,
        pkt_buf,
        new_delta_len,
        new_delta_buf);
    if (res != ERROR_OK)
        return res;
    for (unsigned int i = 0; i < ctx->cores_num; i++) {
        if (pkt_core_id == i)
            continue;
        switch (event_id) {
        /* messages below should be sent to trace destinations for all cores */
        case SYSVIEW_EVTID_TRACE_START:
        case SYSVIEW_EVTID_TRACE_STOP:
        case SYSVIEW_EVTID_SYSTIME_CYCLES:
        case SYSVIEW_EVTID_SYSTIME_US:
        case SYSVIEW_EVTID_SYSDESC:
        case SYSVIEW_EVTID_TASK_INFO:
        case SYSVIEW_EVTID_STACK_INFO:
        case SYSVIEW_EVTID_MODULEDESC:
        case SYSVIEW_EVTID_INIT:
        case SYSVIEW_EVTID_NUMMODULES:
        case SYSVIEW_EVTID_OVERFLOW:
        case SYSVIEW_EVTID_TASK_START_READY:
            /* if packet's source core has changed */
            wr_len = pkt_len;
            if (pkt_core_changed) {
                /* clone packet with unmodified delta */
                new_delta_len = 0;
            } else {
                /* clone packet with modified delta */
                uint8_t *delta_ptr = new_delta_buf;
                sysview_encode_u32(&delta_ptr, cmd_data->sv_acc_time_delta /*delta has been accumulated above*/);
                wr_len -= delta_len;
                new_delta_len = delta_ptr - new_delta_buf;
            }
            LOG_DEBUG("sysview: Redirect %d bytes of event %d to dest %d", wr_len, event_id, i);
            res = esp32_sysview_write_packet(cmd_data,
                i,
                wr_len,
                pkt_buf,
                new_delta_len,
                new_delta_buf);
            if (res != ERROR_OK)
                return res;
            /* messages above are cloned to trace files for both cores,
            * so reset acc time delta, both files have actual delta
            * info */
            cmd_data->sv_acc_time_delta = 0;
            break;
        default:
            break;
        }
    }
    return ERROR_OK;
}
 
int esp32_sysview_process_data(struct esp32_apptrace_cmd_ctx *ctx,
    unsigned int core_id,
    uint8_t *data,
    uint32_t data_len)
{
    struct esp32_sysview_cmd_data *cmd_data = ctx->cmd_priv;
 
    LOG_DEBUG("sysview: Read from target %d bytes [%x %x %x %x]",
        data_len,
        data[0],
        data[1],
        data[2],
        data[3]);
    int res;
    uint32_t processed = 0;
    if (core_id >= ctx->cores_num) {
        LOG_ERROR("sysview: Invalid core id %d in user block!", core_id);
        return ERROR_FAIL;
    }
    if (cmd_data->mcore_format)
        core_id = 0;
    if (ctx->tot_len == 0) {
        /* handle sync seq */
        if (data_len < SYSVIEW_SYNC_LEN) {
            LOG_ERROR("sysview: Invalid init seq len %d!", data_len);
            return ERROR_FAIL;
        }
        LOG_DEBUG("sysview: Process %d sync bytes", SYSVIEW_SYNC_LEN);
        uint8_t sync_seq[SYSVIEW_SYNC_LEN] = { 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0 };
        if (memcmp(data, sync_seq, SYSVIEW_SYNC_LEN) != 0) {
            LOG_ERROR("sysview: Invalid init seq [%x %x %x %x %x %x %x %x %x %x]",
                data[0], data[1], data[2], data[3], data[4], data[5], data[6],
                data[7], data[8], data[9]);
            return ERROR_FAIL;
        }
        res = cmd_data->data_dests[core_id].write(cmd_data->data_dests[core_id].priv,
            data,
            SYSVIEW_SYNC_LEN);
        if (res != ERROR_OK) {
            LOG_ERROR("sysview: Failed to write %u sync bytes to dest %d!",
                SYSVIEW_SYNC_LEN,
                core_id);
            return res;
        }
        if (!cmd_data->mcore_format) {
            for (unsigned int i = 0; i < ctx->cores_num; i++) {
                if (core_id == i)
                    continue;
                res =
                    cmd_data->data_dests[i].write(cmd_data->data_dests[i].priv,
                    data,
                    SYSVIEW_SYNC_LEN);
                if (res != ERROR_OK) {
                    LOG_ERROR("sysview: Failed to write %u sync bytes to dest %d!", SYSVIEW_SYNC_LEN, core_id ? 0 : 1);
                    return res;
                }
            }
        }
        ctx->tot_len += SYSVIEW_SYNC_LEN;
        processed += SYSVIEW_SYNC_LEN;
    }
    while (processed < data_len) {
        unsigned int pkt_core_id;
        uint32_t delta_len = 0;
        uint32_t pkt_len = 0, delta = 0;
        uint16_t event_id = esp_sysview_parse_packet(data + processed,
            &pkt_len,
            &pkt_core_id,
            &delta,
            &delta_len,
            !cmd_data->mcore_format);
        LOG_DEBUG("sysview: Process packet: core %d, %d id, %d bytes [%x %x %x %x]",
            pkt_core_id,
            event_id,
            pkt_len,
            data[processed + 0],
            data[processed + 1],
            data[processed + 2],
            data[processed + 3]);
        if (!cmd_data->mcore_format) {
            res = esp32_sysview_process_packet(ctx,
                pkt_core_id,
                event_id,
                delta,
                delta_len,
                pkt_len,
                data + processed);
            if (res != ERROR_OK)
                return res;
        } else {
            res = cmd_data->data_dests[0].write(cmd_data->data_dests[0].priv, data + processed, pkt_len);
            if (res != ERROR_OK) {
                LOG_ERROR("sysview: Failed to write %u bytes to dest %d!", pkt_len, 0);
                return res;
            }
        }
        if (event_id == SYSVIEW_EVTID_TRACE_STOP)
            cmd_data->sv_trace_running = 0;
        ctx->tot_len += pkt_len;
        processed += pkt_len;
    }
    LOG_USER("%u ", ctx->tot_len);
    /* check for stop condition */
    if (ctx->tot_len > cmd_data->apptrace.skip_len &&
        (ctx->tot_len - cmd_data->apptrace.skip_len >= cmd_data->apptrace.max_len)) {
        ctx->running = 0;
        if (duration_measure(&ctx->read_time) != 0) {
            LOG_ERROR("Failed to stop trace read time measure!");
            return ERROR_FAIL;
        }
    }
    return ERROR_OK;
}