[Heap Trace Standalone] improvements to formatting, code, comments

This commit is contained in:
Chip Weinberger 2022-12-08 00:47:02 -08:00
parent aad600c9ca
commit 9afc386dd2
5 changed files with 234 additions and 81 deletions

View File

@ -1,5 +1,5 @@
/* /*
* SPDX-FileCopyrightText: 2018-2021 Espressif Systems (Shanghai) CO LTD * SPDX-FileCopyrightText: 2015-2022 Espressif Systems (Shanghai) CO LTD
* *
* SPDX-License-Identifier: Apache-2.0 * SPDX-License-Identifier: Apache-2.0
*/ */
@ -69,11 +69,26 @@ esp_err_t heap_trace_get(size_t index, heap_trace_record_t *record)
return ESP_ERR_NOT_SUPPORTED; return ESP_ERR_NOT_SUPPORTED;
} }
esp_err_t heap_trace_summary(heap_trace_summary_t *summary)
{
return ESP_ERR_NOT_SUPPORTED;
}
void heap_trace_dump(void) void heap_trace_dump(void)
{ {
return; return;
} }
void heap_trace_dump_internal_ram(void)
{
return;
}
void heap_trace_dump_psram(void)
{
return;
}
/* Add a new allocation to the heap trace records */ /* Add a new allocation to the heap trace records */
static IRAM_ATTR void record_allocation(const heap_trace_record_t *record) static IRAM_ATTR void record_allocation(const heap_trace_record_t *record)
{ {

View File

@ -23,16 +23,33 @@ static portMUX_TYPE trace_mux = portMUX_INITIALIZER_UNLOCKED;
static bool tracing; static bool tracing;
static heap_trace_mode_t mode; static heap_trace_mode_t mode;
/* Buffer used for records, starting at offset 0 typedef struct {
*/
static heap_trace_record_t *buffer;
static size_t total_records;
/* Count of entries logged in the buffer. /* Buffer used for records, starting at offset 0 */
heap_trace_record_t *buffer;
Maximum total_records /* capacity of the buffer */
*/ size_t capacity;
static size_t count;
/* Count of entries logged in the buffer.*/
size_t count;
/* During execution, we remember the maximum
value of 'count'. This can help you
choose the right size for your buffer capacity.*/
size_t high_water_mark;
/* Has the buffer overflowed and lost trace entries? */
bool has_overflowed;
} records_t;
// Forward Defines
static void remove_record(records_t *r, int index);
static void heap_trace_dump_base(bool internal_ram, bool psram);
/* The actual records. */
static records_t records;
/* Actual number of allocations logged */ /* Actual number of allocations logged */
static size_t total_allocations; static size_t total_allocations;
@ -40,34 +57,36 @@ static size_t total_allocations;
/* Actual number of frees logged */ /* Actual number of frees logged */
static size_t total_frees; static size_t total_frees;
/* Has the buffer overflowed and lost trace entries? */
static bool has_overflowed = false;
esp_err_t heap_trace_init_standalone(heap_trace_record_t *record_buffer, size_t num_records) esp_err_t heap_trace_init_standalone(heap_trace_record_t *record_buffer, size_t num_records)
{ {
if (tracing) { if (tracing) {
return ESP_ERR_INVALID_STATE; return ESP_ERR_INVALID_STATE;
} }
buffer = record_buffer;
total_records = num_records; records.buffer = record_buffer;
memset(buffer, 0, num_records * sizeof(heap_trace_record_t)); records.capacity = num_records;
memset(records.buffer, 0, num_records * sizeof(heap_trace_record_t));
return ESP_OK; return ESP_OK;
} }
esp_err_t heap_trace_start(heap_trace_mode_t mode_param) esp_err_t heap_trace_start(heap_trace_mode_t mode_param)
{ {
if (buffer == NULL || total_records == 0) { if (records.buffer == NULL || records.capacity == 0) {
return ESP_ERR_INVALID_STATE; return ESP_ERR_INVALID_STATE;
} }
portENTER_CRITICAL(&trace_mux); portENTER_CRITICAL(&trace_mux);
tracing = false; tracing = false;
mode = mode_param; mode = mode_param;
count = 0;
records.count = 0;
records.has_overflowed = false;
total_allocations = 0; total_allocations = 0;
total_frees = 0; total_frees = 0;
has_overflowed = false;
heap_trace_resume(); heap_trace_resume();
portEXIT_CRITICAL(&trace_mux); portEXIT_CRITICAL(&trace_mux);
@ -95,7 +114,7 @@ esp_err_t heap_trace_resume(void)
size_t heap_trace_get_count(void) size_t heap_trace_get_count(void)
{ {
return count; return records.count;
} }
esp_err_t heap_trace_get(size_t index, heap_trace_record_t *record) esp_err_t heap_trace_get(size_t index, heap_trace_record_t *record)
@ -103,32 +122,83 @@ esp_err_t heap_trace_get(size_t index, heap_trace_record_t *record)
if (record == NULL) { if (record == NULL) {
return ESP_ERR_INVALID_STATE; return ESP_ERR_INVALID_STATE;
} }
esp_err_t result = ESP_OK; esp_err_t result = ESP_OK;
portENTER_CRITICAL(&trace_mux); portENTER_CRITICAL(&trace_mux);
if (index >= count) {
if (index >= records.count) {
result = ESP_ERR_INVALID_ARG; /* out of range for 'count' */ result = ESP_ERR_INVALID_ARG; /* out of range for 'count' */
} else { } else {
memcpy(record, &buffer[index], sizeof(heap_trace_record_t)); memcpy(record, &records.buffer[index], sizeof(heap_trace_record_t));
} }
portEXIT_CRITICAL(&trace_mux); portEXIT_CRITICAL(&trace_mux);
return result; return result;
} }
esp_err_t heap_trace_summary(heap_trace_summary_t *summary)
{
if (summary == NULL) {
return ESP_ERR_INVALID_ARG;
}
void heap_trace_dump(void) portENTER_CRITICAL(&trace_mux);
summary->mode = mode;
summary->total_allocations = total_allocations;
summary->total_frees = total_frees;
summary->count = records.count;
summary->capacity = records.capacity;
summary->high_water_mark = records.high_water_mark;
summary->has_overflowed = records.has_overflowed;
portEXIT_CRITICAL(&trace_mux);
return ESP_OK;
}
void heap_trace_dump_internal_ram(void) {
heap_trace_dump_base(true, false);
}
void heap_trace_dump_psram(void) {
heap_trace_dump_base(false, true);
}
void heap_trace_dump(void) {
heap_trace_dump_base(true, true);
}
static void heap_trace_dump_base(bool internal_ram, bool psram)
{ {
size_t delta_size = 0; size_t delta_size = 0;
size_t delta_allocs = 0; size_t delta_allocs = 0;
printf("%u allocations trace (%u entry buffer)\n", size_t start_count = records.count;
count, total_records);
size_t start_count = count; printf("====== Heap Trace: %u records (%u capacity) ======\n",
for (int i = 0; i < count; i++) { records.count, records.capacity);
heap_trace_record_t *rec = &buffer[i];
for (int i = 0; i < records.count; i++) {
heap_trace_record_t *rec = &records.buffer[i];
bool should_print = rec->address != NULL &&
((psram && internal_ram) ||
(internal_ram && esp_ptr_internal(rec->address)) ||
(psram && esp_ptr_external_ram(rec->address)));
if (should_print) {
const char* label = "";
if (esp_ptr_internal(rec->address)) {
label = ", Internal";
}
if (esp_ptr_external_ram(rec->address)) {
label = ", PSRAM";
}
printf("%6d bytes (@ %p%s) allocated CPU %d ccount 0x%08x caller ",
rec->size, rec->address, label, rec->ccount & 1, rec->ccount & ~3);
if (rec->address != NULL) {
printf("%d bytes (@ %p) allocated CPU %d ccount 0x%08x caller ",
rec->size, rec->address, rec->ccount & 1, rec->ccount & ~3);
for (int j = 0; j < STACK_DEPTH && rec->alloced_by[j] != 0; j++) { for (int j = 0; j < STACK_DEPTH && rec->alloced_by[j] != 0; j++) {
printf("%p%s", rec->alloced_by[j], printf("%p%s", rec->alloced_by[j],
(j < STACK_DEPTH - 1) ? ":" : ""); (j < STACK_DEPTH - 1) ? ":" : "");
@ -147,19 +217,31 @@ void heap_trace_dump(void)
} }
} }
} }
printf("====== Heap Trace Summary ======\n");
if (mode == HEAP_TRACE_ALL) { if (mode == HEAP_TRACE_ALL) {
printf("Mode: Heap Trace All\n");
printf("%u bytes alive in trace (%u/%u allocations)\n", printf("%u bytes alive in trace (%u/%u allocations)\n",
delta_size, delta_allocs, heap_trace_get_count()); delta_size, delta_allocs, heap_trace_get_count());
} else { } else {
printf("Mode: Heap Trace Leaks\n");
printf("%u bytes 'leaked' in trace (%u allocations)\n", delta_size, delta_allocs); printf("%u bytes 'leaked' in trace (%u allocations)\n", delta_size, delta_allocs);
} }
printf("total allocations %u total frees %u\n", total_allocations, total_frees);
if (start_count != count) { // only a problem if trace isn't stopped before dumping printf("records: %u (%u capacity, %u high water mark)\n",
records.count, records.capacity, records.high_water_mark);
printf("total allocations: %u\n", total_allocations);
printf("total frees: %u\n", total_frees);
if (start_count != records.count) { // only a problem if trace isn't stopped before dumping
printf("(NB: New entries were traced while dumping, so trace dump may have duplicate entries.)\n"); printf("(NB: New entries were traced while dumping, so trace dump may have duplicate entries.)\n");
} }
if (has_overflowed) { if (records.has_overflowed) {
printf("(NB: Buffer has overflowed, so trace data is incomplete.)\n"); printf("(NB: Internal Buffer has overflowed, so trace data is incomplete.)\n");
} }
printf("================================\n");
} }
/* Add a new allocation to the heap trace records */ /* Add a new allocation to the heap trace records */
@ -170,30 +252,44 @@ static IRAM_ATTR void record_allocation(const heap_trace_record_t *record)
} }
portENTER_CRITICAL(&trace_mux); portENTER_CRITICAL(&trace_mux);
if (tracing) { if (tracing) {
if (count == total_records) {
has_overflowed = true; if (records.count == records.capacity) {
records.has_overflowed = true;
/* Move the whole buffer back one slot. /* Move the whole buffer back one slot.
This is a bit slow, compared to treating this buffer as a ringbuffer and rotating a head pointer. This is a bit slow, compared to treating this buffer as a
ringbuffer and rotating a head pointer.
However, ringbuffer code gets tricky when we remove elements in mid-buffer (for leak trace mode) while However, ringbuffer code gets tricky when we remove elements
trying to keep track of an item count that may overflow. in mid-buffer (for leak trace mode) while trying to keep
track of an item count that may overflow.
*/ */
memmove(&buffer[0], &buffer[1], sizeof(heap_trace_record_t) * (total_records -1)); memmove(&records.buffer[0], &records.buffer[1],
count--; sizeof(heap_trace_record_t) * (records.capacity -1));
records.count--;
} }
// Copy new record into place // Copy new record into place
memcpy(&buffer[count], record, sizeof(heap_trace_record_t)); memcpy(&records.buffer[records.count], record, sizeof(heap_trace_record_t));
count++;
records.count++;
// high water mark
if (records.count > records.high_water_mark) {
records.high_water_mark = records.count;
}
total_allocations++; total_allocations++;
} }
portEXIT_CRITICAL(&trace_mux); portEXIT_CRITICAL(&trace_mux);
} }
// remove a record, used when freeing
static void remove_record(int index);
/* record a free event in the heap trace log /* record a free event in the heap trace log
For HEAP_TRACE_ALL, this means filling in the freed_by pointer. For HEAP_TRACE_ALL, this means filling in the freed_by pointer.
@ -206,42 +302,53 @@ static IRAM_ATTR void record_free(void *p, void **callers)
} }
portENTER_CRITICAL(&trace_mux); portENTER_CRITICAL(&trace_mux);
if (tracing && count > 0) {
if (tracing) {
total_frees++; total_frees++;
/* search backwards for the allocation record matching this free */ /* search backwards for the allocation record matching this free */
int i; int i = -1;
for (i = count - 1; i >= 0; i--) { if (records.count > 0) {
if (buffer[i].address == p) { for (i = records.count - 1; i >= 0; i--) {
break; if (records.buffer[i].address == p) {
break;
}
} }
} }
if (i >= 0) { if (i >= 0) {
if (mode == HEAP_TRACE_ALL) { if (mode == HEAP_TRACE_ALL) {
memcpy(buffer[i].freed_by, callers, sizeof(void *) * STACK_DEPTH);
// add 'freed_by' info to the record
memcpy(records.buffer[i].freed_by, callers, sizeof(void *) * STACK_DEPTH);
} else { // HEAP_TRACE_LEAKS } else { // HEAP_TRACE_LEAKS
// Leak trace mode, once an allocation is freed we remove it from the list
remove_record(i); // Leak trace mode, once an allocation is freed
// we remove it from the list
remove_record(&records, i);
} }
} }
} }
portEXIT_CRITICAL(&trace_mux); portEXIT_CRITICAL(&trace_mux);
} }
/* remove the entry at 'index' from the ringbuffer of saved records */ /* remove the entry at 'index' from the ringbuffer of saved records */
static IRAM_ATTR void remove_record(int index) static IRAM_ATTR void remove_record(records_t *r, int index)
{ {
if (index < count - 1) { if (index < r->count - 1) {
// Remove the buffer entry from the list // Remove the buffer entry from the list
memmove(&buffer[index], &buffer[index+1], memmove(&r->buffer[index], &r->buffer[index+1],
sizeof(heap_trace_record_t) * (total_records - index - 1)); sizeof(heap_trace_record_t) * (r->capacity - index - 1));
} else { } else {
// For last element, just zero it out to avoid ambiguity // For last element, just zero it out to avoid ambiguity
memset(&buffer[index], 0, sizeof(heap_trace_record_t)); memset(&r->buffer[index], 0, sizeof(heap_trace_record_t));
} }
count--; r->count--;
} }
#include "heap_trace.inc" #include "heap_trace.inc"
#endif /*CONFIG_HEAP_TRACING_STANDALONE*/ #endif // CONFIG_HEAP_TRACING_STANDALONE

View File

@ -1,16 +1,8 @@
// Copyright 2015-2016 Espressif Systems (Shanghai) PTE LTD /*
// * SPDX-FileCopyrightText: 2015-2022 Espressif Systems (Shanghai) CO LTD
// Licensed under the Apache License, Version 2.0 (the "License"); *
// you may not use this file except in compliance with the License. * SPDX-License-Identifier: Apache-2.0
// You may obtain a copy of the License at */
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
#pragma once #pragma once
#include "sdkconfig.h" #include "sdkconfig.h"
@ -45,6 +37,19 @@ typedef struct {
void *freed_by[CONFIG_HEAP_TRACING_STACK_DEPTH]; ///< Call stack of the caller which freed the memory (all zero if not freed.) void *freed_by[CONFIG_HEAP_TRACING_STACK_DEPTH]; ///< Call stack of the caller which freed the memory (all zero if not freed.)
} heap_trace_record_t; } heap_trace_record_t;
/**
* @brief Stores information about the result of a heap trace.
*/
typedef struct {
heap_trace_mode_t mode; ///< The heap trace mode we just completed / are running
size_t total_allocations; ///< The total number of allocations made during tracing
size_t total_frees; ///< The total number of frees made during tracing
size_t count; ///< The number of records in the internal buffer
size_t capacity; ///< The capacity of the internal buffer
size_t high_water_mark; ///< The maximum value that 'count' got to
size_t has_overflowed; ///< True if the internal buffer overflowed at some point
} heap_trace_summary_t;
/** /**
* @brief Initialise heap tracing in standalone mode. * @brief Initialise heap tracing in standalone mode.
* *
@ -52,8 +57,8 @@ typedef struct {
* *
* To disable heap tracing and allow the buffer to be freed, stop tracing and then call heap_trace_init_standalone(NULL, 0); * To disable heap tracing and allow the buffer to be freed, stop tracing and then call heap_trace_init_standalone(NULL, 0);
* *
* @param record_buffer Provide a buffer to use for heap trace data. Must remain valid any time heap tracing is enabled, meaning * @param record_buffer Provide a buffer to use for heap trace data.
* it must be allocated from internal memory not in PSRAM. * Note: External RAM is allowed, but it prevents recording allocations made from ISR's.
* @param num_records Size of the heap trace buffer, as number of record structures. * @param num_records Size of the heap trace buffer, as number of record structures.
* @return * @return
* - ESP_ERR_NOT_SUPPORTED Project was compiled without heap tracing enabled in menuconfig. * - ESP_ERR_NOT_SUPPORTED Project was compiled without heap tracing enabled in menuconfig.
@ -126,7 +131,8 @@ size_t heap_trace_get_count(void);
/** /**
* @brief Return a raw record from the heap trace buffer * @brief Return a raw record from the heap trace buffer
* *
* @note It is safe to call this function while heap tracing is running, however in HEAP_TRACE_LEAK mode record indexing may * @note It is safe to call this function while heap tracing is
* running, however in HEAP_TRACE_LEAK mode record indexing may
* skip entries unless heap tracing is stopped first. * skip entries unless heap tracing is stopped first.
* *
* @param index Index (zero-based) of the record to return. * @param index Index (zero-based) of the record to return.
@ -142,13 +148,38 @@ esp_err_t heap_trace_get(size_t index, heap_trace_record_t *record);
/** /**
* @brief Dump heap trace record data to stdout * @brief Dump heap trace record data to stdout
* *
* @note It is safe to call this function while heap tracing is running, however in HEAP_TRACE_LEAK mode the dump may skip * @note It is safe to call this function while heap tracing is
* running, however in HEAP_TRACE_LEAK mode the dump may skip
* entries unless heap tracing is stopped first. * entries unless heap tracing is stopped first.
*
*
*/ */
void heap_trace_dump(void); void heap_trace_dump(void);
/**
* @brief Same as heap_trace_dump() but will only log allocations in Internal-RAM
*
* @note It is safe to call this function while heap tracing is
* running, however in HEAP_TRACE_LEAK mode the dump may skip
* entries unless heap tracing is stopped first.
*/
void heap_trace_dump_internal_ram(void);
/**
* @brief Same as heap_trace_dump() but will only log allocations in PSRAM
*
* @note It is safe to call this function while heap tracing is
* running, however in HEAP_TRACE_LEAK mode the dump may skip
* entries unless heap tracing is stopped first.
*/
void heap_trace_dump_psram(void);
/**
* @brief Get summary information about the result of a heap trace
*
* @note It is safe to call this function while heap tracing is running.
*/
esp_err_t heap_trace_summary(heap_trace_summary_t *summary);
#ifdef __cplusplus #ifdef __cplusplus
} }
#endif #endif

View File

@ -253,6 +253,7 @@ In ``HEAP_TRACE_LEAKS`` mode, for each traced memory allocation which has not al
- ``XX bytes`` is the number of bytes allocated - ``XX bytes`` is the number of bytes allocated
- ``@ 0x...`` is the heap address returned from malloc/calloc. - ``@ 0x...`` is the heap address returned from malloc/calloc.
- ``Internal`` or ``PSRAM`` is the general location of the allocated memory.
- ``CPU x`` is the CPU (0 or 1) running when the allocation was made. - ``CPU x`` is the CPU (0 or 1) running when the allocation was made.
- ``ccount 0x...`` is the CCOUNT (CPU cycle count) register value when the allocation was mode. Is different for CPU 0 vs CPU 1. - ``ccount 0x...`` is the CCOUNT (CPU cycle count) register value when the allocation was mode. Is different for CPU 0 vs CPU 1.
:CONFIG_IDF_TARGET_ARCH_XTENSA: - ``caller 0x...`` gives the call stack of the call to malloc()/free(), as a list of PC addresses. These can be decoded to source files and line numbers, as shown above. :CONFIG_IDF_TARGET_ARCH_XTENSA: - ``caller 0x...`` gives the call stack of the call to malloc()/free(), as a list of PC addresses. These can be decoded to source files and line numbers, as shown above.

View File

@ -715,7 +715,6 @@ components/hal/test/test_mpu.c
components/hal/touch_sensor_hal.c components/hal/touch_sensor_hal.c
components/hal/uart_hal_iram.c components/hal/uart_hal_iram.c
components/hal/usb_hal.c components/hal/usb_hal.c
components/heap/include/esp_heap_trace.h
components/heap/include/heap_memory_layout.h components/heap/include/heap_memory_layout.h
components/heap/test/test_aligned_alloc_caps.c components/heap/test/test_aligned_alloc_caps.c
components/heap/test/test_allocator_timings.c components/heap/test/test_allocator_timings.c