diff --git a/doc/guides/tracing/index.rst b/doc/guides/tracing/index.rst index a66af4063e5..164439c688d 100644 --- a/doc/guides/tracing/index.rst +++ b/doc/guides/tracing/index.rst @@ -71,7 +71,7 @@ infrastructure for #5 and #6. This leaves #3 serialization code and #4 I/O mechanics up to a custom implementation. This CTF debug module aims at providing a common #1 and #2 for Zephyr -("middle"), while providing a lean & generic interface for I/O ("bottom"). +("top"), while providing a lean & generic interface for I/O ("bottom"). Currently, only one CTF bottom-layer exists, POSIX ``fwrite``, but many others are possible: @@ -82,7 +82,7 @@ are possible: In fact, I/O varies greatly from system to system. Therefore, it is instructive to create a taxonomy for I/O types when we must ensure the -interface between CTF-middle and CTF-bottom is generic and efficient +interface between CTF-top and CTF-bottom is generic and efficient enough to model these. See the *I/O taxonomy* section below. @@ -105,17 +105,17 @@ The bottom-layer then needs to implement the following macros: - ``CTF_BOTTOM_FIELDS``: Var-args of fields. May process each field with ``MAP`` - ``CTF_BOTTOM_TIMESTAMPED_INTERNALLY``: Tells where timestamping is done -These macros along with inline functions of the middle-layer can yield a +These macros along with inline functions of the top-layer can yield a very low-overhead tracing infrastructure. -CTF Middle-Layer Example +CTF Top-Layer Example ========================= The CTF_EVENT macro will serialize each argument to a field:: /* Example for illustration */ - static inline void ctf_middle_foo(u32_t thread_id, ctf_bounded_string_t name) + static inline void ctf_top_foo(u32_t thread_id, ctf_bounded_string_t name) { CTF_EVENT( CTF_LITERAL(u8_t, 42), @@ -170,11 +170,11 @@ See also the presentation by Ericsson, Future LTTng Inspiration ======================== -Currently, the middle-layer provided here is quite simple and bare-bones, +Currently, the top-layer provided here is quite simple and bare-bones, and needlessly copied from Zephyr's Segger SystemView debug module. For an OS like Zephyr, it would make sense to draw inspiration from -Linux's LTTng and change the middle-layer to serialize to the same format. +Linux's LTTng and change the top-layer to serialize to the same format. Doing this would enable direct reuse of TraceCompass' canned analyses for Linux. Alternatively, LTTng-analyses in TraceCompass could be customized to Zephyr. It is ongoing work to enable TraceCompass diff --git a/subsys/debug/tracing/ctf/ctf_middle.h b/subsys/debug/tracing/ctf/ctf_middle.h deleted file mode 100644 index 17559e83901..00000000000 --- a/subsys/debug/tracing/ctf/ctf_middle.h +++ /dev/null @@ -1,230 +0,0 @@ -/* - * Copyright (c) 2018 Oticon A/S - * - * SPDX-License-Identifier: Apache-2.0 - */ - -#ifndef SUBSYS_DEBUG_TRACING_CTF_MIDDLE_H -#define SUBSYS_DEBUG_TRACING_CTF_MIDDLE_H - -#include -#include -#include - -/* Limit strings to 20 bytes to optimize bandwidth */ -#define CTF_MAX_STRING_LEN 20 - -/* Optionally enter into a critical region, decided by bottom layer */ -#define CTF_CRITICAL_REGION(x) \ - { \ - CTF_BOTTOM_LOCK(); \ - x; \ - CTF_BOTTOM_UNLOCK(); \ - } - - -#ifdef CTF_BOTTOM_TIMESTAMPED_EXTERNALLY -/* Emit CTF event using the bottom-level IO mechanics */ -#define CTF_EVENT(...) \ - { \ - CTF_CRITICAL_REGION(CTF_BOTTOM_FIELDS(__VA_ARGS__)) \ - } -#endif /* CTF_BOTTOM_TIMESTAMPED_EXTERNALLY */ - -#ifdef CTF_BOTTOM_TIMESTAMPED_INTERNALLY -/* Emit CTF event using the bottom-level IO mechanics. Prefix by sample time */ -#define CTF_EVENT(...) \ - { \ - const u32_t tstamp = k_cycle_get_32(); \ - CTF_CRITICAL_REGION(CTF_BOTTOM_FIELDS(tstamp, __VA_ARGS__)) \ - } -#endif /* CTF_BOTTOM_TIMESTAMPED_INTERNALLY */ - - -/* Anonymous compound literal with 1 member. Legal since C99. - * This permits us to take the address of literals, like so: - * &CTF_LITERAL(int, 1234) - * - * This may be required if a ctf_bottom layer uses memcpy. - * - * NOTE string literals already support address-of and sizeof, - * so string literals should not be wrapped with CTF_LITERAL. - */ -#define CTF_LITERAL(type, value) ((type) { (type)(value) }) - - -typedef enum { - CTF_EVENT_THREAD_SWITCHED_OUT = 0x10, - CTF_EVENT_THREAD_SWITCHED_IN = 0x11, - CTF_EVENT_THREAD_PRIORITY_SET = 0x12, - CTF_EVENT_THREAD_CREATE = 0x13, - CTF_EVENT_THREAD_ABORT = 0x14, - CTF_EVENT_THREAD_SUSPEND = 0x15, - CTF_EVENT_THREAD_RESUME = 0x16, - CTF_EVENT_THREAD_READY = 0x17, - CTF_EVENT_THREAD_PENDING = 0x18, - CTF_EVENT_THREAD_INFO = 0x19, - CTF_EVENT_THREAD_NAME_SET = 0x1A, - CTF_EVENT_ISR_ENTER = 0x20, - CTF_EVENT_ISR_EXIT = 0x21, - CTF_EVENT_ISR_EXIT_TO_SCHEDULER = 0x22, - CTF_EVENT_IDLE = 0x30, - CTF_EVENT_ID_START_CALL = 0x41, - CTF_EVENT_ID_END_CALL = 0x42 -} ctf_event_t; - - -typedef struct { - char buf[CTF_MAX_STRING_LEN]; -} ctf_bounded_string_t; - - -static inline void ctf_middle_thread_switched_out(u32_t thread_id) -{ - CTF_EVENT( - CTF_LITERAL(u8_t, CTF_EVENT_THREAD_SWITCHED_OUT), - thread_id - ); -} - -static inline void ctf_middle_thread_switched_in(u32_t thread_id) -{ - CTF_EVENT( - CTF_LITERAL(u8_t, CTF_EVENT_THREAD_SWITCHED_IN), - thread_id - ); -} - -static inline void ctf_middle_thread_priority_set(u32_t thread_id, s8_t prio) -{ - CTF_EVENT( - CTF_LITERAL(u8_t, CTF_EVENT_THREAD_PRIORITY_SET), - thread_id, - prio - ); -} - -static inline void ctf_middle_thread_create( - u32_t thread_id, - s8_t prio, - ctf_bounded_string_t name - ) -{ - CTF_EVENT( - CTF_LITERAL(u8_t, CTF_EVENT_THREAD_CREATE), - thread_id, - name - ); -} - -static inline void ctf_middle_thread_abort(u32_t thread_id) -{ - CTF_EVENT( - CTF_LITERAL(u8_t, CTF_EVENT_THREAD_ABORT), - thread_id - ); -} - -static inline void ctf_middle_thread_suspend(u32_t thread_id) -{ - CTF_EVENT( - CTF_LITERAL(u8_t, CTF_EVENT_THREAD_SUSPEND), - thread_id - ); -} - -static inline void ctf_middle_thread_resume(u32_t thread_id) -{ - CTF_EVENT( - CTF_LITERAL(u8_t, CTF_EVENT_THREAD_RESUME), - thread_id - ); -} - -static inline void ctf_middle_thread_ready(u32_t thread_id) -{ - CTF_EVENT( - CTF_LITERAL(u8_t, CTF_EVENT_THREAD_READY), - thread_id - ); -} - -static inline void ctf_middle_thread_pend(u32_t thread_id) -{ - CTF_EVENT( - CTF_LITERAL(u8_t, CTF_EVENT_THREAD_PENDING), - thread_id - ); -} - -static inline void ctf_middle_thread_info( - u32_t thread_id, - u32_t stack_base, - u32_t stack_size - ) -{ - CTF_EVENT( - CTF_LITERAL(u8_t, CTF_EVENT_THREAD_INFO), - thread_id, - stack_base, - stack_size - ); -} - -static inline void ctf_middle_thread_name_set( - u32_t thread_id, - ctf_bounded_string_t name - ) -{ - CTF_EVENT( - CTF_LITERAL(u8_t, CTF_EVENT_THREAD_NAME_SET), - thread_id, - name - ); -} - -static inline void ctf_middle_isr_enter(void) -{ - CTF_EVENT( - CTF_LITERAL(u8_t, CTF_EVENT_ISR_ENTER) - ); -} - -static inline void ctf_middle_isr_exit(void) -{ - CTF_EVENT( - CTF_LITERAL(u8_t, CTF_EVENT_ISR_EXIT) - ); -} - -static inline void ctf_middle_isr_exit_to_scheduler(void) -{ - CTF_EVENT( - CTF_LITERAL(u8_t, CTF_EVENT_ISR_EXIT_TO_SCHEDULER) - ); -} - -static inline void ctf_middle_idle(void) -{ - CTF_EVENT( - CTF_LITERAL(u8_t, CTF_EVENT_IDLE) - ); -} - -static inline void ctf_middle_void(u32_t id) -{ - CTF_EVENT( - CTF_LITERAL(u8_t, CTF_EVENT_ID_START_CALL), - id - ); -} - -static inline void ctf_middle_end_call(u32_t id) -{ - CTF_EVENT( - CTF_LITERAL(u8_t, CTF_EVENT_ID_END_CALL), - id - ); -} - -#endif /* SUBSYS_DEBUG_TRACING_CTF_MIDDLE_H */ diff --git a/subsys/debug/tracing/ctf/ctf_top.c b/subsys/debug/tracing/ctf/ctf_top.c index 3ed4e30925f..f56a001834e 100644 --- a/subsys/debug/tracing/ctf/ctf_top.c +++ b/subsys/debug/tracing/ctf/ctf_top.c @@ -7,8 +7,6 @@ #include #include #include - -#include #include "ctf_top.h" @@ -29,20 +27,20 @@ void sys_trace_thread_switched_out(void) { struct k_thread *thread = k_current_get(); - ctf_middle_thread_switched_out((u32_t)(uintptr_t)thread); + ctf_top_thread_switched_out((u32_t)(uintptr_t)thread); } void sys_trace_thread_switched_in(void) { struct k_thread *thread = k_current_get(); - ctf_middle_thread_switched_in((u32_t)(uintptr_t)thread); + ctf_top_thread_switched_in((u32_t)(uintptr_t)thread); } void sys_trace_thread_priority_set(struct k_thread *thread) { - ctf_middle_thread_priority_set((u32_t)(uintptr_t)thread, - thread->base.prio); + ctf_top_thread_priority_set((u32_t)(uintptr_t)thread, + thread->base.prio); } void sys_trace_thread_create(struct k_thread *thread) @@ -57,14 +55,14 @@ void sys_trace_thread_create(struct k_thread *thread) } #endif - ctf_middle_thread_create( + ctf_top_thread_create( (u32_t)(uintptr_t)thread, thread->base.prio, name ); #if defined(CONFIG_THREAD_STACK_INFO) - ctf_middle_thread_info( + ctf_top_thread_info( (u32_t)(uintptr_t)thread, thread->stack_info.size, thread->stack_info.start @@ -74,33 +72,33 @@ void sys_trace_thread_create(struct k_thread *thread) void sys_trace_thread_abort(struct k_thread *thread) { - ctf_middle_thread_abort((u32_t)(uintptr_t)thread); + ctf_top_thread_abort((u32_t)(uintptr_t)thread); } void sys_trace_thread_suspend(struct k_thread *thread) { - ctf_middle_thread_suspend((u32_t)(uintptr_t)thread); + ctf_top_thread_suspend((u32_t)(uintptr_t)thread); } void sys_trace_thread_resume(struct k_thread *thread) { - ctf_middle_thread_resume((u32_t)(uintptr_t)thread); + ctf_top_thread_resume((u32_t)(uintptr_t)thread); } void sys_trace_thread_ready(struct k_thread *thread) { - ctf_middle_thread_ready((u32_t)(uintptr_t)thread); + ctf_top_thread_ready((u32_t)(uintptr_t)thread); } void sys_trace_thread_pend(struct k_thread *thread) { - ctf_middle_thread_pend((u32_t)(uintptr_t)thread); + ctf_top_thread_pend((u32_t)(uintptr_t)thread); } void sys_trace_thread_info(struct k_thread *thread) { #if defined(CONFIG_THREAD_STACK_INFO) - ctf_middle_thread_info( + ctf_top_thread_info( (u32_t)(uintptr_t)thread, thread->stack_info.size, thread->stack_info.start @@ -118,7 +116,7 @@ void sys_trace_thread_name_set(struct k_thread *thread) /* strncpy may not always null-terminate */ name.buf[sizeof(name.buf) - 1] = 0; } - ctf_middle_thread_name_set( + ctf_top_thread_name_set( (u32_t)(uintptr_t)thread, name ); @@ -127,32 +125,32 @@ void sys_trace_thread_name_set(struct k_thread *thread) void sys_trace_isr_enter(void) { - ctf_middle_isr_enter(); + ctf_top_isr_enter(); } void sys_trace_isr_exit(void) { - ctf_middle_isr_exit(); + ctf_top_isr_exit(); } void sys_trace_isr_exit_to_scheduler(void) { - ctf_middle_isr_exit_to_scheduler(); + ctf_top_isr_exit_to_scheduler(); } void sys_trace_idle(void) { - ctf_middle_idle(); + ctf_top_idle(); } void sys_trace_void(unsigned int id) { - ctf_middle_void(id); + ctf_top_void(id); } void sys_trace_end_call(unsigned int id) { - ctf_middle_end_call(id); + ctf_top_end_call(id); } diff --git a/subsys/debug/tracing/ctf/ctf_top.h b/subsys/debug/tracing/ctf/ctf_top.h index 3136d6825dd..5ac8712b874 100644 --- a/subsys/debug/tracing/ctf/ctf_top.h +++ b/subsys/debug/tracing/ctf/ctf_top.h @@ -7,5 +7,224 @@ #ifndef SUBSYS_DEBUG_TRACING_CTF_TOP_H #define SUBSYS_DEBUG_TRACING_CTF_TOP_H +#include +#include +#include + +/* Limit strings to 20 bytes to optimize bandwidth */ +#define CTF_MAX_STRING_LEN 20 + +/* Optionally enter into a critical region, decided by bottom layer */ +#define CTF_CRITICAL_REGION(x) \ + { \ + CTF_BOTTOM_LOCK(); \ + x; \ + CTF_BOTTOM_UNLOCK(); \ + } + + +#ifdef CTF_BOTTOM_TIMESTAMPED_EXTERNALLY +/* Emit CTF event using the bottom-level IO mechanics */ +#define CTF_EVENT(...) \ + { \ + CTF_CRITICAL_REGION(CTF_BOTTOM_FIELDS(__VA_ARGS__)) \ + } +#endif /* CTF_BOTTOM_TIMESTAMPED_EXTERNALLY */ + +#ifdef CTF_BOTTOM_TIMESTAMPED_INTERNALLY +/* Emit CTF event using the bottom-level IO mechanics. Prefix by sample time */ +#define CTF_EVENT(...) \ + { \ + const u32_t tstamp = k_cycle_get_32(); \ + CTF_CRITICAL_REGION(CTF_BOTTOM_FIELDS(tstamp, __VA_ARGS__)) \ + } +#endif /* CTF_BOTTOM_TIMESTAMPED_INTERNALLY */ + + +/* Anonymous compound literal with 1 member. Legal since C99. + * This permits us to take the address of literals, like so: + * &CTF_LITERAL(int, 1234) + * + * This may be required if a ctf_bottom layer uses memcpy. + * + * NOTE string literals already support address-of and sizeof, + * so string literals should not be wrapped with CTF_LITERAL. + */ +#define CTF_LITERAL(type, value) ((type) { (type)(value) }) + + +typedef enum { + CTF_EVENT_THREAD_SWITCHED_OUT = 0x10, + CTF_EVENT_THREAD_SWITCHED_IN = 0x11, + CTF_EVENT_THREAD_PRIORITY_SET = 0x12, + CTF_EVENT_THREAD_CREATE = 0x13, + CTF_EVENT_THREAD_ABORT = 0x14, + CTF_EVENT_THREAD_SUSPEND = 0x15, + CTF_EVENT_THREAD_RESUME = 0x16, + CTF_EVENT_THREAD_READY = 0x17, + CTF_EVENT_THREAD_PENDING = 0x18, + CTF_EVENT_THREAD_INFO = 0x19, + CTF_EVENT_THREAD_NAME_SET = 0x1A, + CTF_EVENT_ISR_ENTER = 0x20, + CTF_EVENT_ISR_EXIT = 0x21, + CTF_EVENT_ISR_EXIT_TO_SCHEDULER = 0x22, + CTF_EVENT_IDLE = 0x30, + CTF_EVENT_ID_START_CALL = 0x41, + CTF_EVENT_ID_END_CALL = 0x42 +} ctf_event_t; + + +typedef struct { + char buf[CTF_MAX_STRING_LEN]; +} ctf_bounded_string_t; + + +static inline void ctf_top_thread_switched_out(u32_t thread_id) +{ + CTF_EVENT( + CTF_LITERAL(u8_t, CTF_EVENT_THREAD_SWITCHED_OUT), + thread_id + ); +} + +static inline void ctf_top_thread_switched_in(u32_t thread_id) +{ + CTF_EVENT( + CTF_LITERAL(u8_t, CTF_EVENT_THREAD_SWITCHED_IN), + thread_id + ); +} + +static inline void ctf_top_thread_priority_set(u32_t thread_id, s8_t prio) +{ + CTF_EVENT( + CTF_LITERAL(u8_t, CTF_EVENT_THREAD_PRIORITY_SET), + thread_id, + prio + ); +} + +static inline void ctf_top_thread_create( + u32_t thread_id, + s8_t prio, + ctf_bounded_string_t name + ) +{ + CTF_EVENT( + CTF_LITERAL(u8_t, CTF_EVENT_THREAD_CREATE), + thread_id, + name + ); +} + +static inline void ctf_top_thread_abort(u32_t thread_id) +{ + CTF_EVENT( + CTF_LITERAL(u8_t, CTF_EVENT_THREAD_ABORT), + thread_id + ); +} + +static inline void ctf_top_thread_suspend(u32_t thread_id) +{ + CTF_EVENT( + CTF_LITERAL(u8_t, CTF_EVENT_THREAD_SUSPEND), + thread_id + ); +} + +static inline void ctf_top_thread_resume(u32_t thread_id) +{ + CTF_EVENT( + CTF_LITERAL(u8_t, CTF_EVENT_THREAD_RESUME), + thread_id + ); +} + +static inline void ctf_top_thread_ready(u32_t thread_id) +{ + CTF_EVENT( + CTF_LITERAL(u8_t, CTF_EVENT_THREAD_READY), + thread_id + ); +} + +static inline void ctf_top_thread_pend(u32_t thread_id) +{ + CTF_EVENT( + CTF_LITERAL(u8_t, CTF_EVENT_THREAD_PENDING), + thread_id + ); +} + +static inline void ctf_top_thread_info( + u32_t thread_id, + u32_t stack_base, + u32_t stack_size + ) +{ + CTF_EVENT( + CTF_LITERAL(u8_t, CTF_EVENT_THREAD_INFO), + thread_id, + stack_base, + stack_size + ); +} + +static inline void ctf_top_thread_name_set( + u32_t thread_id, + ctf_bounded_string_t name + ) +{ + CTF_EVENT( + CTF_LITERAL(u8_t, CTF_EVENT_THREAD_NAME_SET), + thread_id, + name + ); +} + +static inline void ctf_top_isr_enter(void) +{ + CTF_EVENT( + CTF_LITERAL(u8_t, CTF_EVENT_ISR_ENTER) + ); +} + +static inline void ctf_top_isr_exit(void) +{ + CTF_EVENT( + CTF_LITERAL(u8_t, CTF_EVENT_ISR_EXIT) + ); +} + +static inline void ctf_top_isr_exit_to_scheduler(void) +{ + CTF_EVENT( + CTF_LITERAL(u8_t, CTF_EVENT_ISR_EXIT_TO_SCHEDULER) + ); +} + +static inline void ctf_top_idle(void) +{ + CTF_EVENT( + CTF_LITERAL(u8_t, CTF_EVENT_IDLE) + ); +} + +static inline void ctf_top_void(u32_t id) +{ + CTF_EVENT( + CTF_LITERAL(u8_t, CTF_EVENT_ID_START_CALL), + id + ); +} + +static inline void ctf_top_end_call(u32_t id) +{ + CTF_EVENT( + CTF_LITERAL(u8_t, CTF_EVENT_ID_END_CALL), + id + ); +} #endif /* SUBSYS_DEBUG_TRACING_CTF_TOP_H */