From 66577a9d237ee86f71438e480671a72c3af63186 Mon Sep 17 00:00:00 2001 From: Daniel DeGrasse Date: Mon, 10 Jun 2024 19:54:36 +0000 Subject: [PATCH] tracing: add named event trace Add support for a "named event" trace. This trace is intentionally not used by the system. The purpose of this trace is to allow driver or application developers to quickly add tracing for events for debug purposes, and to provide an example of how tracing subsystems can be extended with additional trace identifiers. Signed-off-by: Daniel DeGrasse --- include/zephyr/tracing/tracing.h | 18 ++++++++++++++++++ scripts/tracing/parse_ctf.py | 5 +++++ subsys/tracing/ctf/ctf_top.c | 11 +++++++++++ subsys/tracing/ctf/ctf_top.h | 8 ++++++++ subsys/tracing/ctf/tracing_ctf.h | 2 ++ subsys/tracing/ctf/tsdl/metadata | 10 ++++++++++ subsys/tracing/sysview/SYSVIEW_Zephyr.txt | 2 ++ subsys/tracing/sysview/sysview.c | 15 +++++++++++++++ subsys/tracing/sysview/tracing_sysview.h | 2 ++ subsys/tracing/sysview/tracing_sysview_ids.h | 2 ++ subsys/tracing/test/tracing_test.h | 2 ++ subsys/tracing/user/tracing_user.h | 2 ++ 12 files changed, 79 insertions(+) diff --git a/include/zephyr/tracing/tracing.h b/include/zephyr/tracing/tracing.h index e969c4eec5c..feb69a74ad7 100644 --- a/include/zephyr/tracing/tracing.h +++ b/include/zephyr/tracing/tracing.h @@ -2376,6 +2376,24 @@ /** @} */ /* end of subsys_tracing_apis_socket */ +/** + * @brief Named Tracing APIs + * @defgroup subsys_tracing_apis_named Named tracing APIs + * @{ + */ + +/* + * @brief Called by user to generate named events + * + * @param name name of event. Tracing subsystems may place a limit on + * the length of this string + * @param arg0 arbitrary user-provided data for this event + * @param arg1 arbitrary user-provided data for this event + */ +#define sys_trace_named_event(name, arg0, arg1) + +/** @} */ /* end of subsys_tracing_apis_named */ + #if defined(CONFIG_PERCEPIO_TRACERECORDER) #include "tracing_tracerecorder.h" #else diff --git a/scripts/tracing/parse_ctf.py b/scripts/tracing/parse_ctf.py index 9979623cfa5..d25553965c6 100644 --- a/scripts/tracing/parse_ctf.py +++ b/scripts/tracing/parse_ctf.py @@ -136,6 +136,11 @@ def main(): c = Fore.MAGENTA print(c + f"{dt} (+{diff_s:.6f} s): {event.name} ({event.payload_field['id']})" + Fore.RESET) + elif event.name in ['named_event']: + name = event.payload_field['name'] + arg0 = event.payload_field['arg0'] + arg1 = event.payload_field['arg1'] + print(f"{dt} (+{diff_s:.6f} s): {event.name} (name: {name}, arg0: {arg0} arg1: {arg1})") else: print(f"{dt} (+{diff_s:.6f} s): {event.name}") diff --git a/subsys/tracing/ctf/ctf_top.c b/subsys/tracing/ctf/ctf_top.c index 12ab43709f3..319ead9134e 100644 --- a/subsys/tracing/ctf/ctf_top.c +++ b/subsys/tracing/ctf/ctf_top.c @@ -746,3 +746,14 @@ void sys_trace_net_tx_time(struct net_pkt *pkt, uint32_t end_time) (uint32_t)tc, (uint32_t)duration_us); } + +void sys_trace_named_event(const char *name, uint32_t arg0, uint32_t arg1) +{ + ctf_bounded_string_t ctf_name = {""}; + + strncpy(ctf_name.buf, name, CTF_MAX_STRING_LEN); + /* Make sure buffer is NULL terminated */ + ctf_name.buf[CTF_MAX_STRING_LEN - 1] = '\0'; + + ctf_named_event(ctf_name, arg0, arg1); +} diff --git a/subsys/tracing/ctf/ctf_top.h b/subsys/tracing/ctf/ctf_top.h index 4929107bfdd..b8e677ba8bb 100644 --- a/subsys/tracing/ctf/ctf_top.h +++ b/subsys/tracing/ctf/ctf_top.h @@ -157,6 +157,7 @@ typedef enum { CTF_EVENT_NET_SEND_DATA_EXIT = 0x5F, CTF_EVENT_NET_RX_TIME = 0x60, CTF_EVENT_NET_TX_TIME = 0x61, + CTF_EVENT_NAMED_EVENT = 0x62, } ctf_event_t; @@ -658,4 +659,11 @@ static inline void ctf_top_net_tx_time(int32_t if_index, uint32_t iface, uint32_ if_index, iface, pkt, priority, tc, duration); } +static inline void ctf_named_event(ctf_bounded_string_t name, uint32_t arg0, + uint32_t arg1) +{ + CTF_EVENT(CTF_LITERAL(uint8_t, CTF_EVENT_NAMED_EVENT), name, + arg0, arg1); +} + #endif /* SUBSYS_DEBUG_TRACING_CTF_TOP_H */ diff --git a/subsys/tracing/ctf/tracing_ctf.h b/subsys/tracing/ctf/tracing_ctf.h index 178bd3b4013..ae62d7bf9bc 100644 --- a/subsys/tracing/ctf/tracing_ctf.h +++ b/subsys/tracing/ctf/tracing_ctf.h @@ -592,6 +592,8 @@ void sys_trace_net_send_data_exit(struct net_pkt *pkt, int ret); void sys_trace_net_rx_time(struct net_pkt *pkt, uint32_t end_time); void sys_trace_net_tx_time(struct net_pkt *pkt, uint32_t end_time); +void sys_trace_named_event(const char *name, uint32_t arg0, uint32_t arg1); + #ifdef __cplusplus } #endif diff --git a/subsys/tracing/ctf/tsdl/metadata b/subsys/tracing/ctf/tsdl/metadata index efaa2adc092..c180200337b 100644 --- a/subsys/tracing/ctf/tsdl/metadata +++ b/subsys/tracing/ctf/tsdl/metadata @@ -777,3 +777,13 @@ event { uint32_t duration_us; }; }; + +event { + name = named_event; + id = 0x62; + fields := struct { + ctf_bounded_string_t name[20]; + uint32_t arg0; + uint32_t arg1; + }; +}; diff --git a/subsys/tracing/sysview/SYSVIEW_Zephyr.txt b/subsys/tracing/sysview/SYSVIEW_Zephyr.txt index e04d2cfa7c4..8e33e848804 100644 --- a/subsys/tracing/sysview/SYSVIEW_Zephyr.txt +++ b/subsys/tracing/sysview/SYSVIEW_Zephyr.txt @@ -169,3 +169,5 @@ TaskState 0xBF 1=dummy, 2=Waiting, 4=New, 8=Terminated, 16=Suspended, 32=Termina 161 pm_device_runtime_disable dev=%I | Returns %u 162 syscall name=%s + +163 named_event name=%s arg0=%u arg1=%u diff --git a/subsys/tracing/sysview/sysview.c b/subsys/tracing/sysview/sysview.c index 59d426fa762..6ca72464bbd 100644 --- a/subsys/tracing/sysview/sysview.c +++ b/subsys/tracing/sysview/sysview.c @@ -10,6 +10,7 @@ #include +#define NAMED_EVENT_MAXSTR 20 /* Maximum string length supported by named event */ static uint32_t interrupt; @@ -65,6 +66,20 @@ void sys_trace_idle(void) SEGGER_SYSVIEW_OnIdle(); } +void sys_trace_named_event(const char *name, uint32_t arg0, uint32_t arg1) +{ + /* Based on SEGGER provided code for user defined packets */ + uint8_t a_packet[SEGGER_SYSVIEW_INFO_SIZE + 2 * + SEGGER_SYSVIEW_QUANTA_U32 + NAMED_EVENT_MAXSTR + 1]; + uint8_t *payload; + + payload = SEGGER_SYSVIEW_PREPARE_PACKET(a_packet); + payload = SEGGER_SYSVIEW_EncodeString(payload, name, NAMED_EVENT_MAXSTR); + payload = SEGGER_SYSVIEW_EncodeU32(payload, arg0); + payload = SEGGER_SYSVIEW_EncodeU32(payload, arg1); + SEGGER_SYSVIEW_SendPacket(a_packet, payload, TID_NAMED_EVENT); +} + static int sysview_init(void) { diff --git a/subsys/tracing/sysview/tracing_sysview.h b/subsys/tracing/sysview/tracing_sysview.h index 33e5ba25560..3d60b7448c1 100644 --- a/subsys/tracing/sysview/tracing_sysview.h +++ b/subsys/tracing/sysview/tracing_sysview.h @@ -639,6 +639,8 @@ void sys_trace_k_thread_ready(struct k_thread *thread); void sys_trace_k_thread_pend(struct k_thread *thread); void sys_trace_k_thread_info(struct k_thread *thread); +void sys_trace_named_event(const char *name, uint32_t arg0, uint32_t arg1); + #define sys_port_trace_pm_system_suspend_enter(ticks) \ SEGGER_SYSVIEW_RecordU32(TID_PM_SYSTEM_SUSPEND, (uint32_t)ticks) #define sys_port_trace_pm_system_suspend_exit(ticks, state) \ diff --git a/subsys/tracing/sysview/tracing_sysview_ids.h b/subsys/tracing/sysview/tracing_sysview_ids.h index 3b8cd870175..d037b172f85 100644 --- a/subsys/tracing/sysview/tracing_sysview_ids.h +++ b/subsys/tracing/sysview/tracing_sysview_ids.h @@ -155,6 +155,8 @@ extern "C" { #define TID_SYSCALL (130u + TID_OFFSET) +#define TID_NAMED_EVENT (131u + TID_OFFSET) + /* latest ID is 130 */ #ifdef __cplusplus diff --git a/subsys/tracing/test/tracing_test.h b/subsys/tracing/test/tracing_test.h index 06a1a7298df..fc3e73e0a02 100644 --- a/subsys/tracing/test/tracing_test.h +++ b/subsys/tracing/test/tracing_test.h @@ -742,4 +742,6 @@ void sys_trace_k_event_init(struct k_event *event); #define sys_trace_sys_init_enter(...) #define sys_trace_sys_init_exit(...) +#define sys_trace_named_event(name, arg0, arg1) + #endif /* ZEPHYR_TRACE_TEST_H */ diff --git a/subsys/tracing/user/tracing_user.h b/subsys/tracing/user/tracing_user.h index 8d663089531..1d3a28032e3 100644 --- a/subsys/tracing/user/tracing_user.h +++ b/subsys/tracing/user/tracing_user.h @@ -390,6 +390,8 @@ void sys_trace_sys_init_exit(const struct init_entry *entry, int level, int resu #define sys_port_trace_net_rx_time(pkt, end_time) #define sys_port_trace_net_tx_time(pkt, end_time) +#define sys_trace_named_event(name, arg0, arg1) + #ifdef __cplusplus } #endif