diff --git a/components/app_trace/heap_trace_tohost.c b/components/app_trace/heap_trace_tohost.c index eee31b55f5..fb19aea6f1 100644 --- a/components/app_trace/heap_trace_tohost.c +++ b/components/app_trace/heap_trace_tohost.c @@ -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 */ @@ -69,11 +69,21 @@ esp_err_t heap_trace_get(size_t index, heap_trace_record_t *record) 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) { return; } +void heap_trace_dump_caps(__attribute__((unused)) const uint32_t caps) +{ + return; +} + /* Add a new allocation to the heap trace records */ static IRAM_ATTR void record_allocation(const heap_trace_record_t *record) { diff --git a/components/heap/heap_trace_standalone.c b/components/heap/heap_trace_standalone.c index b945b0530f..c78f3b3c91 100644 --- a/components/heap/heap_trace_standalone.c +++ b/components/heap/heap_trace_standalone.c @@ -13,6 +13,7 @@ #include "esp_attr.h" #include "freertos/FreeRTOS.h" #include "freertos/task.h" +#include "esp_memory_utils.h" #define STACK_DEPTH CONFIG_HEAP_TRACING_STACK_DEPTH @@ -23,16 +24,33 @@ static portMUX_TYPE trace_mux = portMUX_INITIALIZER_UNLOCKED; static bool tracing; static heap_trace_mode_t mode; -/* Buffer used for records, starting at offset 0 -*/ -static heap_trace_record_t *buffer; -static size_t total_records; +typedef struct { -/* Count of entries logged in the buffer. + /* Buffer used for records, starting at offset 0 */ + heap_trace_record_t *buffer; - Maximum total_records -*/ -static size_t count; + /* capacity of the buffer */ + size_t capacity; + + /* 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 */ static size_t total_allocations; @@ -40,34 +58,36 @@ static size_t total_allocations; /* Actual number of frees logged */ 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) { if (tracing) { return ESP_ERR_INVALID_STATE; } - buffer = record_buffer; - total_records = num_records; - memset(buffer, 0, num_records * sizeof(heap_trace_record_t)); + + records.buffer = record_buffer; + records.capacity = num_records; + memset(records.buffer, 0, num_records * sizeof(heap_trace_record_t)); + return ESP_OK; } 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; } + portENTER_CRITICAL(&trace_mux); tracing = false; mode = mode_param; - count = 0; + + records.count = 0; + records.has_overflowed = false; + total_allocations = 0; total_frees = 0; - has_overflowed = false; heap_trace_resume(); portEXIT_CRITICAL(&trace_mux); @@ -95,7 +115,7 @@ esp_err_t heap_trace_resume(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) @@ -103,32 +123,79 @@ esp_err_t heap_trace_get(size_t index, heap_trace_record_t *record) if (record == NULL) { return ESP_ERR_INVALID_STATE; } + esp_err_t result = ESP_OK; portENTER_CRITICAL(&trace_mux); - if (index >= count) { + + if (index >= records.count) { result = ESP_ERR_INVALID_ARG; /* out of range for 'count' */ } else { - memcpy(record, &buffer[index], sizeof(heap_trace_record_t)); + memcpy(record, &records.buffer[index], sizeof(heap_trace_record_t)); } + portEXIT_CRITICAL(&trace_mux); 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(void) { + heap_trace_dump_caps(MALLOC_CAP_INTERNAL | MALLOC_CAP_SPIRAM); +} + +void heap_trace_dump_caps(const uint32_t caps) { + heap_trace_dump_base(caps & MALLOC_CAP_INTERNAL, caps & MALLOC_CAP_SPIRAM); +} + +static void heap_trace_dump_base(bool internal_ram, bool psram) { size_t delta_size = 0; size_t delta_allocs = 0; - printf("%u allocations trace (%u entry buffer)\n", - count, total_records); - size_t start_count = count; - for (int i = 0; i < count; i++) { - heap_trace_record_t *rec = &buffer[i]; + size_t start_count = records.count; + + printf("====== Heap Trace: %u records (%u capacity) ======\n", + records.count, records.capacity); + + 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++) { printf("%p%s", rec->alloced_by[j], (j < STACK_DEPTH - 1) ? ":" : ""); @@ -147,19 +214,31 @@ void heap_trace_dump(void) } } } + + printf("====== Heap Trace Summary ======\n"); + if (mode == HEAP_TRACE_ALL) { + printf("Mode: Heap Trace All\n"); printf("%u bytes alive in trace (%u/%u allocations)\n", delta_size, delta_allocs, heap_trace_get_count()); } else { + printf("Mode: Heap Trace Leaks\n"); 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"); } - if (has_overflowed) { - printf("(NB: Buffer has overflowed, so trace data is incomplete.)\n"); + if (records.has_overflowed) { + printf("(NB: Internal Buffer has overflowed, so trace data is incomplete.)\n"); } + printf("================================\n"); } /* Add a new allocation to the heap trace records */ @@ -170,30 +249,44 @@ static IRAM_ATTR void record_allocation(const heap_trace_record_t *record) } portENTER_CRITICAL(&trace_mux); + 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. - 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 - trying to keep track of an item count that may overflow. + However, ringbuffer code gets tricky when we remove elements + 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)); - count--; + memmove(&records.buffer[0], &records.buffer[1], + sizeof(heap_trace_record_t) * (records.capacity -1)); + + records.count--; } + // Copy new record into place - memcpy(&buffer[count], record, sizeof(heap_trace_record_t)); - count++; + memcpy(&records.buffer[records.count], record, sizeof(heap_trace_record_t)); + + records.count++; + + // high water mark + if (records.count > records.high_water_mark) { + records.high_water_mark = records.count; + } + total_allocations++; } + 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 For HEAP_TRACE_ALL, this means filling in the freed_by pointer. @@ -206,42 +299,51 @@ static IRAM_ATTR void record_free(void *p, void **callers) } portENTER_CRITICAL(&trace_mux); - if (tracing && count > 0) { + + if (tracing) { + total_frees++; + /* search backwards for the allocation record matching this free */ - int i; - for (i = count - 1; i >= 0; i--) { - if (buffer[i].address == p) { + int i = -1; + for (i = records.count - 1; i >= 0; i--) { + if (records.buffer[i].address == p) { break; } } if (i >= 0) { 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 - // 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); } /* 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 - memmove(&buffer[index], &buffer[index+1], - sizeof(heap_trace_record_t) * (total_records - index - 1)); + memmove(&r->buffer[index], &r->buffer[index+1], + sizeof(heap_trace_record_t) * (r->capacity - index - 1)); } else { // 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" -#endif /*CONFIG_HEAP_TRACING_STANDALONE*/ +#endif // CONFIG_HEAP_TRACING_STANDALONE diff --git a/components/heap/include/esp_heap_trace.h b/components/heap/include/esp_heap_trace.h index a71f96362c..81ac813303 100644 --- a/components/heap/include/esp_heap_trace.h +++ b/components/heap/include/esp_heap_trace.h @@ -1,16 +1,8 @@ -// Copyright 2015-2016 Espressif Systems (Shanghai) PTE LTD -// -// Licensed under the Apache License, Version 2.0 (the "License"); -// you may not use this file except in compliance with the License. -// 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. +/* + * SPDX-FileCopyrightText: 2015-2022 Espressif Systems (Shanghai) CO LTD + * + * SPDX-License-Identifier: Apache-2.0 + */ #pragma once #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.) } 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. * @@ -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); * - * @param record_buffer Provide a buffer to use for heap trace data. Must remain valid any time heap tracing is enabled, meaning - * it must be allocated from internal memory not in PSRAM. + * @param record_buffer Provide a buffer to use for heap trace data. + * 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. * @return * - 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 * - * @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. * * @param index Index (zero-based) of the record to return. @@ -142,13 +148,29 @@ esp_err_t heap_trace_get(size_t index, heap_trace_record_t *record); /** * @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. - * - * */ void heap_trace_dump(void); +/** + * @brief Dump heap trace from the memory of the capabilities passed as parameter. + * + * @param caps Capability(ies) of the memory from which to dump the trace. + * Set MALLOC_CAP_INTERNAL to dump heap trace data from internal memory. + * Set MALLOC_CAP_SPIRAM to dump heap trace data from PSRAM. + * Set both to dump both heap trace data. + */ +void heap_trace_dump_caps(const uint32_t caps); + +/** + * @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 } #endif diff --git a/components/heap/test_apps/main/test_heap_trace.c b/components/heap/test_apps/main/test_heap_trace.c index b88e270b18..4778103b99 100644 --- a/components/heap/test_apps/main/test_heap_trace.c +++ b/components/heap/test_apps/main/test_heap_trace.c @@ -19,12 +19,14 @@ #include "freertos/FreeRTOS.h" #include "freertos/task.h" +#include "esp_heap_caps.h" + #ifdef CONFIG_HEAP_TRACING // only compile in heap tracing tests if tracing is enabled #include "esp_heap_trace.h" -TEST_CASE("heap trace leak check", "[heap]") +TEST_CASE("heap trace leak check", "[heap-trace]") { heap_trace_record_t recs[8]; heap_trace_init_standalone(recs, 8); @@ -71,7 +73,7 @@ TEST_CASE("heap trace leak check", "[heap]") heap_trace_stop(); } -TEST_CASE("heap trace wrapped buffer check", "[heap]") +TEST_CASE("heap trace wrapped buffer check", "[heap-trace]") { const size_t N = 8; heap_trace_record_t recs[N]; @@ -140,7 +142,7 @@ static void print_floats_task(void *ignore) vTaskDelete(NULL); } -TEST_CASE("can trace allocations made by newlib", "[heap]") +TEST_CASE("can trace allocations made by newlib", "[heap-trace]") { const size_t N = 8; heap_trace_record_t recs[N]; @@ -165,5 +167,110 @@ TEST_CASE("can trace allocations made by newlib", "[heap]") TEST_ASSERT(heap_trace_get_count() > 3); } +TEST_CASE("check for summary value validity", "[heap-trace]") { + const size_t alloc_size = 100; + const size_t counter_size = 2; + const size_t ptr_array_size = counter_size + 1; + + // N+1 pointers to allocate to test the overflow in the summary + void *ptrs[ptr_array_size]; + + heap_trace_record_t recs[counter_size]; + heap_trace_init_standalone(recs, counter_size); + heap_trace_start(HEAP_TRACE_ALL); + + for (size_t i = 0; i < ptr_array_size; i ++) { + ptrs[i] = heap_caps_malloc(alloc_size, MALLOC_CAP_INTERNAL); + TEST_ASSERT_NOT_NULL(ptrs[i]); + } + + // check that the summary shows the right number of internal memory allocation count + heap_trace_summary_t summary; + heap_trace_summary(&summary); + TEST_ASSERT(summary.count == counter_size); + TEST_ASSERT(summary.capacity == counter_size); + TEST_ASSERT(summary.total_allocations == ptr_array_size); + TEST_ASSERT(summary.has_overflowed == true); + + // free the pointers + for (size_t i = 0; i < ptr_array_size; i++) { + heap_caps_free(ptrs[i]); + } + + heap_trace_summary(&summary); + TEST_ASSERT(summary.total_frees == ptr_array_size); + + heap_trace_stop(); +} + +#ifdef CONFIG_SPIRAM +void* allocate_pointer(uint32_t caps) +{ + const size_t alloc_size = 100; + void *ptr = heap_caps_malloc(alloc_size, caps); + TEST_ASSERT_NOT_NULL(ptr); + return ptr; +} + +TEST_CASE("can dump only internal memory allocations", "[trace-dump][internal]") +{ + const size_t number_log = 2; + heap_trace_record_t recs[number_log]; + heap_trace_init_standalone(recs, number_log); + heap_trace_start(HEAP_TRACE_ALL); + + void *internal_ptr = allocate_pointer(MALLOC_CAP_INTERNAL); + void *external_ptr = allocate_pointer(MALLOC_CAP_SPIRAM); + + // dump records for memory only. The pytest environment will look for specific strings + // related to internal memory allocation in the output of the dump. + heap_trace_dump_caps(MALLOC_CAP_INTERNAL); + + heap_caps_free(internal_ptr); + heap_caps_free(external_ptr); + + heap_trace_stop(); +} + +TEST_CASE("can dump only external memory allocations", "[trace-dump][external]") +{ + const size_t number_log = 2; + heap_trace_record_t recs[number_log]; + heap_trace_init_standalone(recs, number_log); + heap_trace_start(HEAP_TRACE_ALL); + + void *internal_ptr = allocate_pointer(MALLOC_CAP_INTERNAL); + void *external_ptr = allocate_pointer(MALLOC_CAP_SPIRAM); + + // dump records for memory only. The pytest environment will look for specific strings + // related to external memory allocation in the output of the dump. + heap_trace_dump_caps(MALLOC_CAP_SPIRAM); + + heap_caps_free(internal_ptr); + heap_caps_free(external_ptr); + + heap_trace_stop(); +} + +TEST_CASE("can dump both external and internal allocations", "[trace-dump][all]") +{ + const size_t number_log = 2; + heap_trace_record_t recs[number_log]; + heap_trace_init_standalone(recs, number_log); + heap_trace_start(HEAP_TRACE_ALL); + + void *internal_ptr = allocate_pointer(MALLOC_CAP_INTERNAL); + void *external_ptr = allocate_pointer(MALLOC_CAP_SPIRAM); + + // dump records for memory only. The pytest environment will look for specific strings + // related to external and internal memory allocation in the output of the dump. + heap_trace_dump_caps(MALLOC_CAP_INTERNAL | MALLOC_CAP_SPIRAM); + + heap_caps_free(internal_ptr); + heap_caps_free(external_ptr); + + heap_trace_stop(); +} +#endif // CONFIG_SPIRAM #endif diff --git a/components/heap/test_apps/pytest_heap.py b/components/heap/test_apps/pytest_heap.py index 5fb5b1ae85..1ccc46f047 100644 --- a/components/heap/test_apps/pytest_heap.py +++ b/components/heap/test_apps/pytest_heap.py @@ -65,3 +65,30 @@ def test_heap_8bit_access(dut: Dut) -> None: dut.expect_exact('Press ENTER to see the list of tests') dut.write('"IRAM_8BIT capability test"') dut.expect_unity_test_output(timeout=300) + + +@pytest.mark.generic +@pytest.mark.esp32 +@pytest.mark.parametrize( + 'config', + [ + 'heap_trace' + ] +) +def test_heap_trace_dump(dut: Dut) -> None: + dut.expect_exact('Press ENTER to see the list of tests') + dut.write('[trace-dump][internal]') + dut.expect('Internal') + + dut.expect_exact('Enter next test, or \'enter\' to see menu') + dut.write('[trace-dump][external]') + dut.expect('PSRAM') + + dut.expect_exact('Enter next test, or \'enter\' to see menu') + dut.write('[trace-dump][all]') + dut.expect('Internal') + dut.expect('PSRAM') + + dut.expect_exact('Enter next test, or \'enter\' to see menu') + dut.write('[heap-trace]') + dut.expect_unity_test_output(timeout=100) diff --git a/components/heap/test_apps/sdkconfig.ci.heap_trace b/components/heap/test_apps/sdkconfig.ci.heap_trace new file mode 100644 index 0000000000..fd9162ff5e --- /dev/null +++ b/components/heap/test_apps/sdkconfig.ci.heap_trace @@ -0,0 +1,2 @@ +CONFIG_SPIRAM=y +CONFIG_HEAP_TRACING_STANDALONE=y diff --git a/docs/en/api-reference/system/heap_debug.rst b/docs/en/api-reference/system/heap_debug.rst index 991207704a..6cc9970b86 100644 --- a/docs/en/api-reference/system/heap_debug.rst +++ b/docs/en/api-reference/system/heap_debug.rst @@ -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 - ``@ 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. - ``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. diff --git a/tools/ci/check_copyright_ignore.txt b/tools/ci/check_copyright_ignore.txt index d8b031060a..812c7e17f3 100644 --- a/tools/ci/check_copyright_ignore.txt +++ b/tools/ci/check_copyright_ignore.txt @@ -703,7 +703,6 @@ components/hal/test/test_mpu.c components/hal/touch_sensor_hal.c components/hal/uart_hal_iram.c components/hal/usb_hal.c -components/heap/include/esp_heap_trace.h components/heap/include/heap_memory_layout.h components/heap/test/test_aligned_alloc_caps.c components/heap/test/test_allocator_timings.c