instrumentation: Add instrumentation subsystem

This commit adds the instrumentation subsystem.

Signed-off-by: Gustavo Romero <gustavo.romero@linaro.org>
Signed-off-by: Kevin Townsend <kevin.townsend@linaro.org>
Signed-off-by: Maciej Sobkowski <msobkowski@antmicro.com>
This commit is contained in:
Gustavo Romero
2023-04-27 20:17:23 +00:00
committed by Anas Nashif
parent 217bb19651
commit 139407f818
14 changed files with 1536 additions and 0 deletions

View File

@@ -0,0 +1,191 @@
/*
* Copyright 2023 Linaro
*
* SPDX-License-Identifier: Apache-2.0
*/
#ifndef ZEPHYR_INCLUDE_INSTRUMENTATION_INSTRUMENTATION_H_
#define ZEPHYR_INCLUDE_INSTRUMENTATION_INSTRUMENTATION_H_
#include <zephyr/kernel.h>
#ifdef __cplusplus
extern "C" {
#endif
#if !defined(__no_instrumentation__)
#error "No toolchain support for __no_instrumentation__"
#endif
/**
* @brief Instrumentation event record types.
*/
enum instr_event_types {
INSTR_EVENT_ENTRY = 0, /**< Callee entry event record, followed by instr_event. */
INSTR_EVENT_EXIT, /**< Callee exit event record, followed by instr_event. */
INSTR_EVENT_PROFILE, /**< Profile events */
INSTR_EVENT_SCHED_IN, /**< Thread switched in scheduler event */
INSTR_EVENT_SCHED_OUT, /**< Thread switched out scheduler event */
INSTR_EVENT_NUM, /**< Add more events above this one */
INSTR_EVENT_INVALID /**< Invalid or no event generated after promotion */
} __packed;
/**
* @brief Header for the event records.
*/
struct instr_header {
/** Event type */
enum instr_event_types type;
} __packed;
/**
* @brief Context-specific data of an event.
*/
struct instr_event_context {
/** Arch-specific mode indicator (thread mode, interrupt mode, etc.). */
uint8_t mode: 3;
/** CPU number. */
uint8_t cpu: 5;
/** Thread ID (correlate values with thread lookup table). */
void *thread_id;
#ifdef CONFIG_THREAD_NAME
/** Thread name (that can be compacted with the correlate lookup table). */
char thread_name[CONFIG_THREAD_MAX_NAME_LEN];
#endif
} __packed;
/**
* @brief Event records and associated payloads. Payloads are determined based
* on the code and additional fields in the header.
*/
struct instr_record {
struct instr_header header;
void *callee;
void *caller;
uint64_t timestamp;
union {
struct instr_event_context context; /* Context data */
/* Add more payloads here */
};
} __packed;
/**
* @brief Checks if tracing feature is available.
*
*/
bool instr_tracing_supported(void);
/**
* @brief Checks if profiling feature is available.
*
*/
bool instr_profiling_supported(void);
/**
* @brief Checks if subsystem is ready to be initialized. Must called be before
* instr_init().
*/
bool instr_fundamentals_initialized(void);
/**
* @brief Performs initialisation required by the system.
*/
int instr_init(void);
/**
* @brief Tells if instrumentation subsystem is properly initialized.
*/
bool instr_initialized(void);
/**
* @brief Tells if instrumentation is enabled, i.e. can be turned on.
*/
bool instr_enabled(void);
/**
* @brief Enables instrumentation.
*/
int instr_enable(void);
/**
* @brief Disables instrumentation.
*/
int instr_disable(void);
/**
* @brief Turns on instrumentation (start recording events).
*/
int instr_turn_on(void);
/**
* @brief Turns off instrumentation (stop recording events).
*/
int instr_turn_off(void);
/**
* @brief Tells if instrumentation is turned on.
*/
bool instr_turned_on(void);
/**
* @brief Tells if instrumentation can collect traces.
*/
bool instr_trace_enabled(void);
/**
* @brief Tells if instrumentation can collect profile info.
*/
bool instr_profile_enabled(void);
/**
* @brief Dumps the buffered contents via UART (tracing).
*/
void instr_dump_buffer_uart(void);
/**
* @brief Dumps the delta accumulator array via UART (profiling).
*/
void instr_dump_deltas_uart(void);
/**
* @brief Shared callback handler to process entry/exit events.
*
* @param opcode The type of event to process.
* @param func Address of the function being called.
* @param caller Address of the function caller.
*/
void instr_event_handler(enum instr_event_types opcode, void *func, void *caller);
/**
* @brief Given a function address, set it as the trigger function, i.e. when
* the function is called it will turn on the instrumentation.
*
* @param callee The function address
*/
void instr_set_trigger_func(void *callee);
/**
* @brief Given a function address, set it as the stopper function, i.e. when
* the function exits it will turn off the instrumentation.
*
* @param callee The function address
*/
void instr_set_stop_func(void *callee);
/**
* @brief Get the trigger function address.
*
*/
void *instr_get_trigger_func(void);
/**
* @brief Get the stopper function address.
*
*/
void *instr_get_stop_func(void);
#ifdef __cplusplus
}
#endif
#endif /* ZEPHYR_INCLUDE_INSTRUMENTATION_INSTRUMENTATION_H_ */

View File

@@ -17,6 +17,7 @@ add_subdirectory(debug)
add_subdirectory(fb)
add_subdirectory(fs)
add_subdirectory(gnss)
add_subdirectory(instrumentation)
add_subdirectory(ipc)
add_subdirectory(logging)
add_subdirectory(mem_mgmt)

View File

@@ -25,6 +25,7 @@ source "subsys/fb/Kconfig"
source "subsys/fs/Kconfig"
source "subsys/gnss/Kconfig"
source "subsys/input/Kconfig"
source "subsys/instrumentation/Kconfig"
source "subsys/ipc/Kconfig"
source "subsys/jwt/Kconfig"
source "subsys/llext/Kconfig"

View File

@@ -0,0 +1,24 @@
# Copyright 2023 Linaro
# SPDX-License-Identifier: Apache-2.0
zephyr_sources_ifdef(CONFIG_INSTRUMENTATION
common/instr_common.c
timestamp/timestamp.c
transport/uart.c
)
zephyr_sources_ifdef(CONFIG_INSTRUMENTATION_MODE_CALLGRAPH ringbuffer/ringbuffer.c)
if(CONFIG_INSTRUMENTATION)
if(CMAKE_C_COMPILER_ID STREQUAL "GNU")
zephyr_sources(handlers/instr_handlers_gcc.c)
else()
message(WARNING "CONFIG_INSTRUMENTATION unsupported by this compiler: ${CMAKE_C_COMPILER_ID}.")
endif()
configure_file(${CMAKE_CURRENT_LIST_DIR}/ctf/metadata.template ${CMAKE_BINARY_DIR}/ctf_metadata @ONLY)
endif()
zephyr_compile_definitions_ifdef(CONFIG_INSTRUMENTATION INSTR_TRIGGER_FUNCTION=${CONFIG_INSTRUMENTATION_TRIGGER_FUNCTION})
zephyr_compile_definitions_ifdef(CONFIG_INSTRUMENTATION INSTR_STOPPER_FUNCTION=${CONFIG_INSTRUMENTATION_STOPPER_FUNCTION})
zephyr_include_directories_ifdef(CONFIG_INSTRUMENTATION include)

View File

@@ -0,0 +1,122 @@
# Copyright 2023 Linaro
# SPDX-License-Identifier: Apache-2.0
# Instrumentation configuration options
config INSTRUMENTATION
bool "Compiler Instrumentation Support"
select REBOOT
select RETAINED_MEM
select RETAINED_MEM_ZEPHYR_RAM
select RETAINED_MEM_MUTEX_FORCE_DISABLE
select RETENTION
select RETENTION_MUTEX_FORCE_DISABLE
select UART_INTERRUPT_DRIVEN
help
Enable compiler-managed runtime system instrumentation. This requires
a compiler that supports function instrumentation, and a backend for
capturing and processing those instrumentation events from the target,
like a serial port.
if INSTRUMENTATION
config INSTRUMENTATION_MODE_CALLGRAPH
bool "Call graph mode (Tracing)"
default y
select THREAD_NAME
select TRACING
select TIMING_FUNCTIONS
help
Enables reconstruction of function call graphs and the observation
of context switches (threads), within the limits of the trace buffer
size.
config INSTRUMENTATION_MODE_CALLGRAPH_TRACE_BUFFER_SIZE
int "Size of the trace buffer (bytes)"
depends on INSTRUMENTATION_MODE_CALLGRAPH
default 12000
# Lower limit (in bytes) must match the biggest record item size. For
# details about the sizes, please see instrumentation.h for the record
# struct sizes.
range 20 4294967296
help
Size of the trace buffer. The trace buffer is used to buffer the
tracing events and has two working modes: it can be configure either
as a simple buffer or as a ring buffer (overwriting mode).
config INSTRUMENTATION_MODE_CALLGRAPH_BUFFER_OVERWRITE
bool "Trace buffer overwriting mode"
depends on INSTRUMENTATION_MODE_CALLGRAPH
default y
help
If the trace buffer is set as overwriting it works as a ring buffer.
In this working mode if the buffer gets full old records will be
overwritten by the newer records. This mode allows recording the most
recent tracing events at the expense of losing the old ones. If this
mode is not selected, then once the buffer is full tracing stops.
config INSTRUMENTATION_MODE_STATISTICAL
bool "Statistical mode (Profiling)"
select TIMING_FUNCTIONS
default y
help
Enables statistical profiling of the runtime system, tracking total
execution time of the number of functions equal to
INSTRUMENTATION_MODE_STATISTICAL_MAX_NUM_FUNC.
config INSTRUMENTATION_MODE_STATISTICAL_MAX_NUM_FUNC
int "Maximum number of functions to collect statistics from"
depends on INSTRUMENTATION_MODE_STATISTICAL
default 256
range 1 4096
help
Maximum number of functions to collect statistics from. Set the
maximum number of functions to collect the total execution time for
each function called in the region defined by 'trigger' and 'stopper'
instrumentation points.
config INSTRUMENTATION_MODE_STATISTICAL_MAX_CALL_DEPTH
int "Maximum call depth"
depends on INSTRUMENTATION_MODE_STATISTICAL
default 65535
range 1 65535
help
The maximum number of times a function can be recursively called
before profile data (delta time) stops being collected.
config INSTRUMENTATION_TRIGGER_FUNCTION
string "Default trigger function used to turn on instrumentation"
default "main"
help
Sets the trigger function. Instrumentation (tracing and profiling) is
only turned on when the trigger function is called. The trigger
function can be changed at runtime via the 'zaru' CLI tool.
config INSTRUMENTATION_STOPPER_FUNCTION
string "Default stopper function used to turn off instrumentation"
default "main"
help
Sets the stopper function. Instrumentation (tracing and profiling) is
only turned off when the trigger function returns. The stopper
function can be changed at runtime via the 'zaru' CLI tool.
config INSTRUMENTATION_EXCLUDE_FUNCTION_LIST
string "Exclude function list"
depends on INSTRUMENTATION_MODE_CALLGRAPH || INSTRUMENTATION_MODE_STATISTICAL
help
Set the list of function names to be excluded from instrumentation.
The function name to be matched is its user-visible name. The match is
done on substrings: if the function name in the list is a substring of
a function name, it is considered to be a match. The function names in
the list are separate by a comma, for instance: sym0, sym1, ...
config INSTRUMENTATION_EXCLUDE_FILE_LIST
string "Exclude file list"
depends on INSTRUMENTATION_MODE_CALLGRAPH || INSTRUMENTATION_MODE_STATISTICAL
help
Set the list of files that are excluded from instrumentation. The
match is done on substrings: if the file parameter is a substring of
the file name, it is considered to be a match. The files in the list
are separate by a comma, for instance: file0, file1, ...
endif

View File

@@ -0,0 +1,588 @@
/*
* Copyright 2023 Linaro
* Copyright 2025 Linaro
*
* SPDX-License-Identifier: Apache-2.0
*/
#include <assert.h>
#include <string.h>
#include <zephyr/instrumentation/instrumentation.h>
#include <instr_buffer.h>
#include <instr_timestamp.h>
#include <zephyr/device.h>
#include <zephyr/drivers/uart.h>
#include <zephyr/kernel.h>
#include <zephyr/kernel_structs.h>
#include <zephyr/retention/retention.h>
#include <zephyr/sys/reboot.h>
#include <kernel_internal.h>
#include <ksched.h>
/*
* Memory buffer to store instrumentation event records has the following modes:
*
* Callgraph (tracing) ring buffer (default): Replace oldest entries when buffer
* is full.
*
* Callgraph (tracing) fixed buffer: Stop buffering events when the buffer is
* full, ensuring we have a callgraph from reset point or from wherever the
* trigger function was called for the first time.
*
* Statistical (profiling): Buffer functions until out of memory.
*
*/
const struct device *instrumentation_triggers =
DEVICE_DT_GET(DT_NODELABEL(instrumentation_triggers));
static bool _instr_initialized;
static bool _instr_enabled;
static bool _instr_on;
static bool _instr_tracing_disabled;
static bool _instr_profiling_disabled;
static bool _instr_tracing_supported = IS_ENABLED(CONFIG_INSTRUMENTATION_MODE_CALLGRAPH);
static bool _instr_profiling_supported = IS_ENABLED(CONFIG_INSTRUMENTATION_MODE_STATISTICAL);
#if defined(CONFIG_INSTRUMENTATION_MODE_STATISTICAL)
/*
* Entry for discovered functions. The functions are added to 'disco_func' array
* as they are called in the execution flow, hence "discovered" functions. Once
* MAX_NUM_DISCO_FUNC is reached, additional new executed functions are ignored and
* no profiling information is collected for them.
*/
#define MAX_CALL_DEPTH CONFIG_INSTRUMENTATION_MODE_STATISTICAL_MAX_CALL_DEPTH
struct disco_func_entry {
timing_t entry_timestamp; /* Timestamp at function entry */
uint64_t delta_t; /* Accumulated (per function) delta time */
void *addr; /* Function address/ID */
uint16_t call_depth; /* Call depth */
};
#define MAX_NUM_DISCO_FUNC CONFIG_INSTRUMENTATION_MODE_STATISTICAL_MAX_NUM_FUNC
static int num_disco_func;
struct disco_func_entry disco_func[MAX_NUM_DISCO_FUNC] = { 0 };
/* To track the number of unbalanced/spurious entry/exist pairs, for debugging */
static int unbalanced;
#endif
#ifdef CONFIG_THREAD_NAME
#define THREAD_NAME_NONE "thread-none"
#endif
/* See instr_fundamentals_initialized() */
uint16_t magic = 0xABBA;
/* Defined in Kconfig */
extern int INSTR_TRIGGER_FUNCTION(void);
extern int INSTR_STOPPER_FUNCTION(void);
/* Default trigger and stopper addresses, from Kconfig */
static void *k_trigger_callee = INSTR_TRIGGER_FUNCTION;
static void *k_stopper_callee = INSTR_STOPPER_FUNCTION;
/* Current (live) trigger and stopper addresses */
static void *trigger_callee;
static void *stopper_callee;
bool instr_tracing_supported(void)
{
return _instr_tracing_supported;
}
bool instr_profiling_supported(void)
{
return _instr_profiling_supported;
}
__no_instrumentation__
int instr_init(void)
{
/*
* This function can never be called before RAM is properly initialized. See comment in
* instr_fundamentals_initialized() for more details.
*/
assert(magic == 0xABBA);
/*
* This flag needs to be set before calling any other function, otherwise it will cause an
* infinite recursion in the handler since instr_initialized() will return 0 and
* instr_init() will be called again.
*/
_instr_initialized = 1;
if (retention_is_valid(instrumentation_triggers)) {
/* Retained mem is already initialized, load trigger and stopper addresses */
retention_read(instrumentation_triggers, 0, (uint8_t *)&trigger_callee,
sizeof(trigger_callee));
retention_read(instrumentation_triggers, sizeof(trigger_callee),
(uint8_t *)&stopper_callee, sizeof(stopper_callee));
} else {
/* Retained mem not initialized, so write defaults */
trigger_callee = k_trigger_callee;
retention_write(instrumentation_triggers, 0, (const uint8_t *)&trigger_callee,
sizeof(trigger_callee));
stopper_callee = k_stopper_callee;
retention_write(instrumentation_triggers, sizeof(trigger_callee),
(const uint8_t *)&stopper_callee, sizeof(stopper_callee));
}
#if defined(CONFIG_INSTRUMENTATION_MODE_CALLGRAPH)
/* Initialize ring buffer */
instr_buffer_init();
#endif
/* Init and start counters for timestamping */
instr_timestamp_init();
/*
* Enable instrumentation. When instrumentation is enabled it means it can be turned on and
* off. It will first be turned on when the trigger function is first called and turned off
* when stopper function exits. This two step mechanism allow disabling instrumentation at
* runtime in critical sections inside the instrumentation code by calling instr_disable()/
* instr_enable() at runtime, hence avoiding infinite loop and having to exclude a function
* at compile time. In other words, it allows a better granularity for enabling/disabling
* the instrumentation.
*/
instr_enable();
return 0;
}
__no_instrumentation__
bool instr_initialized(void)
{
return _instr_initialized;
}
/*
* Instrumentation can only be used when RAM is correctly initialized in early
* boot stages and so variables in memory -- for example, _instr_initialized --
* are correctly initialized. To ensure such a condition, a given variable,
* 'magic', has its value in memory checked against a constant (a magic number)
* that is kept in code (flash). Once the value matches the constant it means
* the RAM is correctly initialized and so instrumentation can be initialized
* properly and enabled for use.
*/
__no_instrumentation__
bool instr_fundamentals_initialized(void)
{
if (magic == 0xABBA) {
return true;
} else {
return false;
}
}
__no_instrumentation__
int instr_enable(void)
{
_instr_enabled = true;
return 0;
}
__no_instrumentation__
int instr_disable(void)
{
_instr_enabled = false;
return 0;
}
__no_instrumentation__
bool instr_enabled(void)
{
return _instr_enabled;
}
__no_instrumentation__
int instr_turn_on(void)
{
_instr_on = true;
return 0;
}
__no_instrumentation__
int instr_turn_off(void)
{
_instr_on = false;
return 0;
}
__no_instrumentation__
bool instr_turned_on(void)
{
if (!_instr_enabled) {
/* If instrumentation is disabled always return off state */
return false;
} else {
return _instr_on;
}
}
__no_instrumentation__
bool instr_trace_enabled(void)
{
return !_instr_tracing_disabled;
}
__no_instrumentation__
bool instr_profile_enabled(void)
{
return !_instr_profiling_disabled;
}
__no_instrumentation__
void instr_set_trigger_func(void *callee)
{
/* Update trigger_callee before updating retained mem */
trigger_callee = callee;
retention_write(instrumentation_triggers, 0, (const uint8_t *)&trigger_callee,
sizeof(trigger_callee));
}
__no_instrumentation__
void instr_set_stop_func(void *callee)
{
/* Update stopper_callee before updating retained mem */
stopper_callee = callee;
retention_write(instrumentation_triggers, sizeof(trigger_callee),
(const uint8_t *)&stopper_callee, sizeof(stopper_callee));
}
__no_instrumentation__
void *instr_get_trigger_func(void)
{
return trigger_callee;
}
__no_instrumentation__
void *instr_get_stop_func(void)
{
return stopper_callee;
}
__no_instrumentation__
void instr_dump_buffer_uart(void)
{
#if defined(CONFIG_INSTRUMENTATION_MODE_CALLGRAPH)
static const struct device *const uart_dev =
DEVICE_DT_GET(DT_CHOSEN(zephyr_console));
uint8_t *transferring_buf;
uint32_t transferring_length, instr_buffer_max_length;
/* Make sure instrumentation is disabled. */
instr_disable();
/* Initiator mark */
printk("-*-#");
instr_buffer_max_length = instr_buffer_capacity_get();
while (!instr_buffer_is_empty()) {
transferring_length =
instr_buffer_get_claim(
&transferring_buf,
instr_buffer_max_length);
for (uint32_t i = 0; i < transferring_length; i++) {
uart_poll_out(uart_dev, transferring_buf[i]);
}
instr_buffer_get_finish(transferring_length);
}
/* Terminator mark */
printk("-*-!\n");
#endif
}
__no_instrumentation__
void instr_dump_deltas_uart(void)
{
#if defined(CONFIG_INSTRUMENTATION_MODE_STATISTICAL)
static const struct device *const uart_dev =
DEVICE_DT_GET(DT_CHOSEN(zephyr_console));
instr_disable();
/* Initiator mark */
printk("-*-#");
for (int i = 0; i < num_disco_func; i++) {
uart_poll_out(uart_dev, INSTR_EVENT_PROFILE);
for (int j = 0; j < sizeof(disco_func[i].addr); j++) {
uart_poll_out(uart_dev, *((uint8_t *)&disco_func[i].addr + j));
}
for (int k = 0; k < sizeof(disco_func[i].delta_t); k++) {
uart_poll_out(uart_dev, *((uint8_t *)&disco_func[i].delta_t + k));
}
}
/* Terminator mark */
printk("-*-!\n");
#endif
}
#if defined(CONFIG_INSTRUMENTATION_MODE_STATISTICAL)
__no_instrumentation__
void push_callee_timestamp(void *callee)
{
bool found = false;
int curr_func;
/* Find callee in the discovered function array */
for (curr_func = 0; curr_func < num_disco_func; curr_func++) {
if (disco_func[curr_func].addr == callee) {
found = 1;
break;
}
}
if (!found) { /* New function discovered */
if (num_disco_func >= MAX_NUM_DISCO_FUNC) {
/* No more space to add another function */
return;
}
disco_func[curr_func].delta_t = 0;
disco_func[curr_func].call_depth = 0;
disco_func[curr_func].addr = callee;
num_disco_func++;
}
/* New function or no other instance of function active (called): record timestamp */
if (disco_func[curr_func].call_depth == 0) {
disco_func[curr_func].entry_timestamp = instr_timestamp_ns();
}
/* Update call depth if not reached out maximum call depth */
if (disco_func[curr_func].call_depth < MAX_CALL_DEPTH) {
disco_func[curr_func].call_depth++;
}
}
__no_instrumentation__
void pop_callee_timestamp(void *callee)
{
uint64_t dt_ns;
uint64_t entry_timestamp;
uint64_t exit_timestamp;
int curr_func;
for (curr_func = 0; curr_func < num_disco_func; curr_func++) {
if (disco_func[curr_func].addr == callee) {
disco_func[curr_func].call_depth--;
/* Last active function is returning */
if (disco_func[curr_func].call_depth == 0) {
entry_timestamp = disco_func[curr_func].entry_timestamp;
exit_timestamp = instr_timestamp_ns(); /* Now */
/* Compute delta T */
dt_ns = exit_timestamp - entry_timestamp;
/* Accumulate delta T */
disco_func[curr_func].delta_t += dt_ns;
}
return;
}
}
/* Track number of unbalanced/spurious function exits */
unbalanced++;
}
#endif
__no_instrumentation__
void save_context(struct instr_record *record)
{
k_tid_t curr_thread;
curr_thread = k_current_get();
record->context.cpu = arch_proc_id();
record->context.thread_id = curr_thread;
record->context.mode = curr_thread ? k_thread_priority_get(curr_thread) : 0;
#ifdef CONFIG_THREAD_NAME
if (curr_thread) {
k_thread_name_copy(curr_thread, record->context.thread_name,
sizeof(record->context.thread_name));
} else { /* Not in a thread context */
strncpy(record->context.thread_name,
THREAD_NAME_NONE, sizeof(record->context.thread_name));
}
#endif
}
#if defined(CONFIG_INSTRUMENTATION_MODE_CALLGRAPH)
__no_instrumentation__
enum instr_event_types promote_event_type(enum instr_event_types type, void *callee,
unsigned int *lock_key)
{
/*
* Context switch events.
*/
/*
* Only when z_thread_mark_switched_in/out are entered a trace event is
* recorded, i.e. it doesn't matter when such a functions return. So
* scheduler INSTR_EVENT_EXIT events are discarded by promoting them to
* INSTR_EVENT_INVALID. Later, on the host side, a pair of in and out
* INSTR_EVENT_ENTRY events will be used to compose a single ftrace
* sched_switch event.
*/
if (callee == z_thread_mark_switched_in) {
if (type == INSTR_EVENT_EXIT) {
return INSTR_EVENT_INVALID;
}
*lock_key = irq_lock();
type = INSTR_EVENT_SCHED_IN;
}
if (callee == z_thread_mark_switched_out) {
if (type == INSTR_EVENT_EXIT) {
return INSTR_EVENT_INVALID;
}
*lock_key = irq_lock();
type = INSTR_EVENT_SCHED_OUT;
}
/*
* Other ENTRY and EXIT events are not promoted.
*/
/*
* Add other type promotions below.
* ...
*/
return type;
}
#endif
__no_instrumentation__
static void set_up_record(struct instr_record *record, enum instr_event_types type,
void *callee, void *caller)
{
record->header.type = type;
record->callee = callee;
record->caller = caller;
record->timestamp = instr_timestamp_ns();
save_context(record);
}
static bool instr_record_data_put(struct instr_record *record)
{
uint32_t total_size = 0U;
uint8_t *data = (uint8_t *) record, *buf;
uint32_t length = sizeof(struct instr_record), claimed_size;
/* If record won't fit, free enough space in the buffer */
if (instr_buffer_space_get() < sizeof(struct instr_record)) {
instr_buffer_get(NULL, sizeof(struct instr_record));
}
do {
claimed_size = instr_buffer_put_claim(&buf, length);
memcpy(buf, data, claimed_size);
total_size += claimed_size;
length -= claimed_size;
data += claimed_size;
} while (length && claimed_size);
if (length && claimed_size == 0) {
instr_buffer_put_finish(0);
return false;
}
instr_buffer_put_finish(total_size);
return true;
}
__no_instrumentation__
void instr_event_handler(enum instr_event_types type, void *callee, void *caller)
{
#if defined(CONFIG_INSTRUMENTATION_MODE_CALLGRAPH)
/* For IRQ locking */
unsigned int key = 0;
#endif
/*
* Essentially, the instrumented code can only generate events when a
* function is called or returns. Event type promotion happens based on
* context, when entry and exit events are transformed to new ones based
* on the context (see promote_event_type).
*/
assert(type == INSTR_EVENT_ENTRY || type == INSTR_EVENT_EXIT);
if (!instr_turned_on()) {
return;
}
/* Enter critical section */
instr_disable();
#if defined(CONFIG_INSTRUMENTATION_MODE_STATISTICAL)
/* Profiling */
if (!_instr_profiling_disabled) {
if (type == INSTR_EVENT_ENTRY) {
/* Record current timestamp */
push_callee_timestamp(callee);
}
if (type == INSTR_EVENT_EXIT) {
/* Compute delta time for callee and accumulate it */
pop_callee_timestamp(callee);
}
}
#endif
#if defined(CONFIG_INSTRUMENTATION_MODE_CALLGRAPH)
/* For tracing, promote type based on the context */
type = promote_event_type(type, callee, &key);
if (type == INSTR_EVENT_INVALID) {
/* Don't trace invalid events */
instr_enable();
return;
}
/* Tracing */
if (!_instr_tracing_disabled) {
struct instr_record record;
if (!IS_ENABLED(CONFIG_INSTRUMENTATION_MODE_CALLGRAPH_BUFFER_OVERWRITE) &&
instr_buffer_space_get() < sizeof(struct instr_record)) {
_instr_tracing_disabled = 1;
return;
}
set_up_record(&record, type, callee, caller);
instr_record_data_put(&record);
}
if (type == INSTR_EVENT_SCHED_IN ||
type == INSTR_EVENT_SCHED_OUT) {
irq_unlock(key);
}
#endif
instr_enable();
}

View File

@@ -0,0 +1,97 @@
/* CTF 1.8 */
typealias integer { size = 8; align = 8; signed = true; } := int8_t;
typealias integer { size = 8; align = 8; signed = false; } := uint8_t;
typealias integer { size = 16; align = 8; signed = false; } := uint16_t;
typealias integer { size = 32; align = 8; signed = false; } := uint32_t;
typealias integer { size = 32; align = 8; signed = true; } := int32_t;
typealias integer { size = 64; align = 8; signed = false; } := uint64_t;
typealias integer { size = 5; signed = false; } := uint5_t;
typealias integer { size = 1; signed = false; } := uint1_t;
typealias integer { size = 2; signed = false; } := uint2_t;
typealias integer { size = 3; signed = false; } := uint3_t;
typealias integer { size = 8; align = 8; signed = false; encoding = ASCII; } := string_t;
trace {
major = 1;
minor = 8;
byte_order = le;
};
struct event_header {
enum : uint8_t { META = 0, EVENT = 1 ... 7 } id;
};
stream {
event.header := struct event_header;
};
event {
name = func_entry_with_context;
id = 0;
fields := struct {
uint32_t callee;
uint32_t caller;
uint64_t timestamp;
uint3_t mode;
uint3_t cpu;
uint2_t rsvd;
uint32_t thread_id;
string_t thread_name[20];
};
};
event {
name = func_exit_with_context;
id = 1;
fields := struct {
uint32_t callee;
uint32_t caller;
uint64_t timestamp;
uint3_t mode;
uint3_t cpu;
uint2_t rsvd;
uint32_t thread_id;
string_t thread_name[20];
};
};
event {
name = profile;
id = 2;
fields := struct {
uint32_t callee;
uint64_t delta_t;
};
};
event {
name = sched_switched_in;
id = 3;
fields := struct {
uint32_t callee;
uint32_t caller;
uint64_t timestamp;
uint3_t mode;
uint3_t cpu;
uint2_t rsvd;
uint32_t thread_id;
string_t thread_name[20];
};
};
event {
name = sched_switched_out;
id = 4;
fields := struct {
uint32_t callee;
uint32_t caller;
uint64_t timestamp;
uint3_t mode;
uint3_t cpu;
uint2_t rsvd;
uint32_t thread_id;
string_t thread_name[20];
};
};

View File

@@ -0,0 +1,93 @@
/* CTF 1.8 */
typealias integer { size = 8; align = 8; signed = true; } := int8_t;
typealias integer { size = 8; align = 8; signed = false; } := uint8_t;
typealias integer { size = 16; align = 8; signed = false; } := uint16_t;
typealias integer { size = 32; align = 8; signed = false; } := uint32_t;
typealias integer { size = 32; align = 8; signed = true; } := int32_t;
typealias integer { size = 64; align = 8; signed = false; } := uint64_t;
typealias integer { size = 5; signed = false; } := uint5_t;
typealias integer { size = 1; signed = false; } := uint1_t;
typealias integer { size = 2; signed = false; } := uint2_t;
typealias integer { size = 3; signed = false; } := uint3_t;
typealias integer { size = 8; align = 8; signed = false; encoding = ASCII; } := string_t;
trace {
major = 1;
minor = 8;
byte_order = le;
};
struct event_header {
enum : uint8_t { META = 0, EVENT = 1 ... 7 } id;
};
stream {
event.header := struct event_header;
};
event {
name = func_entry_with_context;
id = 0;
fields := struct {
uint32_t callee;
uint32_t caller;
uint64_t timestamp;
uint3_t mode;
uint5_t cpu;
uint32_t thread_id;
string_t thread_name[@CONFIG_THREAD_MAX_NAME_LEN@];
};
};
event {
name = func_exit_with_context;
id = 1;
fields := struct {
uint32_t callee;
uint32_t caller;
uint64_t timestamp;
uint3_t mode;
uint5_t cpu;
uint32_t thread_id;
string_t thread_name[@CONFIG_THREAD_MAX_NAME_LEN@];
};
};
event {
name = profile;
id = 2;
fields := struct {
uint32_t callee;
uint64_t delta_t;
};
};
event {
name = sched_switched_in;
id = 3;
fields := struct {
uint32_t callee;
uint32_t caller;
uint64_t timestamp;
uint3_t mode;
uint5_t cpu;
uint32_t thread_id;
string_t thread_name[@CONFIG_THREAD_MAX_NAME_LEN@];
};
};
event {
name = sched_switched_out;
id = 4;
fields := struct {
uint32_t callee;
uint32_t caller;
uint64_t timestamp;
uint3_t mode;
uint5_t cpu;
uint32_t thread_id;
string_t thread_name[@CONFIG_THREAD_MAX_NAME_LEN@];
};
};

View File

@@ -0,0 +1,57 @@
/*
* Copyright 2023 Linaro
*
* SPDX-License-Identifier: Apache-2.0
*/
#include <zephyr/instrumentation/instrumentation.h>
#include <instr_timestamp.h>
__no_instrumentation__
void __cyg_profile_func_enter(void *callee, void *caller)
{
/*
* On early boot it's not always possible to initialize the
* instrumentation. Only when instr_fundamentals_initialized returns
* true is when it's possible to initialize and enable the
* instrumentation subsys.
*/
if (!instr_fundamentals_initialized()) {
return;
}
/* It's now possible to initialize and enable the instrumentation */
if (!instr_initialized()) {
instr_init();
}
/* Turn on instrumentation if trigger is called */
if (callee == instr_get_trigger_func() && !instr_turned_on()) {
instr_turn_on();
}
if (!instr_enabled()) {
return;
}
instr_event_handler(INSTR_EVENT_ENTRY, callee, caller);
}
__no_instrumentation__
void __cyg_profile_func_exit(void *callee, void *caller)
{
if (!instr_fundamentals_initialized()) {
return;
}
if (!instr_enabled()) {
return;
}
instr_event_handler(INSTR_EVENT_EXIT, callee, caller);
/* Turn off instrumentation if stopper returns */
if (callee == instr_get_stop_func() && instr_turned_on()) {
instr_turn_off();
}
}

View File

@@ -0,0 +1,111 @@
/*
* Copyright (c) 2025 Antmicro
*
* SPDX-License-Identifier: Apache-2.0
*/
#ifndef _TRACE_BUFFER_H
#define _TRACE_BUFFER_H
#include <stdbool.h>
#include <zephyr/types.h>
#ifdef __cplusplus
extern "C" {
#endif
/**
* @brief Initialize instrumentation buffer.
*/
void instr_buffer_init(void);
/**
* @brief Instrumentation buffer is empty or not.
*
* @return true if the ring buffer is empty, or false if not.
*/
bool instr_buffer_is_empty(void);
/**
* @brief Get free space in the instrumentation buffer.
*
* @return Instrumentation buffer free space (in bytes).
*/
uint32_t instr_buffer_space_get(void);
/**
* @brief Get instrumentation buffer capacity (max size).
*
* @return Instrumentation buffer capacity (in bytes).
*/
uint32_t instr_buffer_capacity_get(void);
/**
* @brief Try to allocate buffer in the instrumentation buffer.
*
* @param data Pointer to the address. It's set to a location
* within the instrumentation buffer.
* @param size Requested buffer size (in bytes).
*
* @return Size of allocated buffer which can be smaller than
* requested if there isn't enough free space or buffer wraps.
*/
uint32_t instr_buffer_put_claim(uint8_t **data, uint32_t size);
/**
* @brief Indicate number of bytes written to the allocated buffer.
*
* @param size Number of bytes written to the allocated buffer.
*
* @retval 0 Successful operation.
* @retval -EINVAL Given @a size exceeds free space of instrumentation buffer.
*/
int instr_buffer_put_finish(uint32_t size);
/**
* @brief Write data to instrumentation buffer.
*
* @param data Address of data.
* @param size Data size (in bytes).
*
* @retval Number of bytes written to instrumentation buffer.
*/
uint32_t instr_buffer_put(uint8_t *data, uint32_t size);
/**
* @brief Get address of the first valid data in instrumentation buffer.
*
* @param data Pointer to the address. It's set to a location pointing to
* the first valid data within the instrumentation buffer.
* @param size Requested buffer size (in bytes).
*
* @return Size of valid buffer which can be smaller than requested
* if there isn't enough valid data or buffer wraps.
*/
uint32_t instr_buffer_get_claim(uint8_t **data, uint32_t size);
/**
* @brief Indicate number of bytes read from claimed buffer.
*
* @param size Number of bytes read from claimed buffer.
*
* @retval 0 Successful operation.
* @retval -EINVAL Given @a size exceeds available data of instrumentation buffer.
*/
int instr_buffer_get_finish(uint32_t size);
/**
* @brief Read data from instrumentation buffer to output buffer.
*
* @param data Address of the output buffer.
* @param size Data size (in bytes).
*
* @retval Number of bytes written to the output buffer.
*/
uint32_t instr_buffer_get(uint8_t *data, uint32_t size);
#ifdef __cplusplus
}
#endif
#endif

View File

@@ -0,0 +1,26 @@
/*
* Copyright 2023 Linaro
*
* SPDX-License-Identifier: Apache-2.0
*/
#ifndef ZEPHYR_INCLUDE_INSTRUMENTATION_TIMESTAMP_H_
#define ZEPHYR_INCLUDE_INSTRUMENTATION_TIMESTAMP_H_
#include <inttypes.h>
#include <zephyr/timing/timing.h>
/**
* @brief Initialize timestamp
*
*/
int instr_timestamp_init(void);
/**
* @brief Get current timestamp in nanoseconds
*
*/
uint64_t instr_timestamp_ns(void);
#endif /* ZEPHYR_INCLUDE_INSTRUMENTATION_TIMESTAMP_H_ */

View File

@@ -0,0 +1,62 @@
/*
* Copyright (c) 2025 Antmicro
* Copyright (c) 2025 Analog Devices
*
* SPDX-License-Identifier: Apache-2.0
*/
#include <zephyr/sys/ring_buffer.h>
static struct ring_buf instr_ring_buf;
static uint8_t instr_buffer[CONFIG_INSTRUMENTATION_MODE_CALLGRAPH_TRACE_BUFFER_SIZE + 1];
uint32_t instr_buffer_put_claim(uint8_t **data, uint32_t size)
{
return ring_buf_put_claim(&instr_ring_buf, data, size);
}
int instr_buffer_put_finish(uint32_t size)
{
return ring_buf_put_finish(&instr_ring_buf, size);
}
uint32_t instr_buffer_put(uint8_t *data, uint32_t size)
{
return ring_buf_put(&instr_ring_buf, data, size);
}
uint32_t instr_buffer_get_claim(uint8_t **data, uint32_t size)
{
return ring_buf_get_claim(&instr_ring_buf, data, size);
}
int instr_buffer_get_finish(uint32_t size)
{
return ring_buf_get_finish(&instr_ring_buf, size);
}
uint32_t instr_buffer_get(uint8_t *data, uint32_t size)
{
return ring_buf_get(&instr_ring_buf, data, size);
}
void instr_buffer_init(void)
{
ring_buf_init(&instr_ring_buf,
sizeof(instr_buffer), instr_buffer);
}
bool instr_buffer_is_empty(void)
{
return ring_buf_is_empty(&instr_ring_buf);
}
uint32_t instr_buffer_capacity_get(void)
{
return ring_buf_capacity_get(&instr_ring_buf);
}
uint32_t instr_buffer_space_get(void)
{
return ring_buf_space_get(&instr_ring_buf);
}

View File

@@ -0,0 +1,30 @@
/*
* Copyright 2023 Linaro
*
* SPDX-License-Identifier: Apache-2.0
*/
#include <zephyr/instrumentation/instrumentation.h>
#include <instr_timestamp.h>
__no_instrumentation__
int instr_timestamp_init(void)
{
timing_init();
timing_start();
return 0;
}
__no_instrumentation__
uint64_t instr_timestamp_ns(void)
{
timing_t bigbang = 0;
timing_t now;
uint64_t now_cycles;
now = timing_counter_get();
now_cycles = timing_cycles_get(&bigbang, &now);
return timing_cycles_to_ns(now_cycles);
}

View File

@@ -0,0 +1,133 @@
/*
* Copyright 2023 Linaro
*
* SPDX-License-Identifier: Apache-2.0
*/
#include <errno.h>
#include <ctype.h>
#include <string.h>
#include <stdlib.h>
#include <zephyr/sys/__assert.h>
#include <zephyr/sys/reboot.h>
#include <zephyr/kernel.h>
#include <zephyr/drivers/uart.h>
#include <zephyr/instrumentation/instrumentation.h>
#define COMMAND_BUFFER_SIZE 32
char _cmd_buffer[COMMAND_BUFFER_SIZE];
__no_instrumentation__
void handle_cmd(char *cmd, uint32_t length)
{
char *beginptr;
char *endptr;
long address;
if (strncmp("reboot", cmd, length) == 0) {
sys_reboot(SYS_REBOOT_COLD);
} else if (strncmp("status", cmd, length) == 0) {
printk("%d %d\n", instr_tracing_supported(), instr_profiling_supported());
} else if (strncmp("ping", cmd, length) == 0) {
printk("pong\n");
} else if (strncmp("dump_trace", cmd, length) == 0) {
instr_dump_buffer_uart();
} else if (strncmp("dump_profile", cmd, length) == 0) {
instr_dump_deltas_uart();
} else if (strncmp(cmd, "trigger", strlen("trigger")) == 0) {
beginptr = cmd + strlen("trigger");
address = strtol(beginptr, &endptr, 16);
if (endptr != beginptr) {
instr_set_trigger_func((void *)address);
} else {
printk("trigger: invalid argument in: '%s'\n", cmd);
}
} else if (strncmp(cmd, "stopper", strlen("stopper")) == 0) {
beginptr = cmd + strlen("stopper");
address = strtol(beginptr, &endptr, 16);
if (endptr != beginptr) {
instr_set_stop_func((void *)address);
} else {
printk("stopper: invalid argument in: '%s'\n", cmd);
}
} else if (strncmp("listsets", cmd, length) == 0) {
void *address;
address = instr_get_trigger_func();
if (address) {
printk("trigger: %p\n", address);
} else {
printk("trigger: not set.\n");
}
address = instr_get_stop_func();
if (address) {
printk("stopper: %p\n", address);
} else {
printk("stopper: not set.\n");
}
} else {
printk("invalid command %s\n", cmd);
}
}
__no_instrumentation__
static void uart_isr(const struct device *uart_dev, void *user_data)
{
uint8_t byte = 0;
static uint32_t cur;
ARG_UNUSED(user_data);
if (!uart_irq_update(uart_dev)) {
return;
}
if (!uart_irq_rx_ready(uart_dev)) {
return;
}
while (uart_fifo_read(uart_dev, &byte, 1) == 1) {
if (!isprint(byte)) {
if (byte == '\r') {
_cmd_buffer[cur] = '\0';
handle_cmd(_cmd_buffer, cur);
cur = 0U;
}
continue;
}
if (cur < (COMMAND_BUFFER_SIZE - 1)) {
_cmd_buffer[cur++] = byte;
}
}
}
__no_instrumentation__
static int uart_isr_init(void)
{
static const struct device *const uart_dev = DEVICE_DT_GET(DT_CHOSEN(zephyr_console));
__ASSERT(device_is_ready(uart_dev), "uart_dev is not ready");
uart_irq_rx_disable(uart_dev);
uart_irq_tx_disable(uart_dev);
/* Set RX irq. handler */
uart_irq_callback_user_data_set(uart_dev, uart_isr, NULL);
/* Clean RX FIFO before enabling interrupt. */
while (uart_irq_rx_ready(uart_dev)) {
uint8_t c;
uart_fifo_read(uart_dev, &c, 1);
}
/* Enable RX interruption. */
uart_irq_rx_enable(uart_dev);
return 0;
}
SYS_INIT(uart_isr_init, APPLICATION, 0);