debug: tracing: Common Trace Format Simplification

Remove ctf_middle layer and have only ctf_top and ctf_bottom.
Port functionality from ctf_middle to ctf_top and remove
ctf_middle.h file. Update associated documentation.

Signed-off-by: Mrinal Sen <msen@oticon.com>
This commit is contained in:
Mrinal Sen 2019-09-16 19:24:07 +02:00 committed by Anas Nashif
commit 9fbc5fcd16
4 changed files with 245 additions and 258 deletions

View file

@ -71,7 +71,7 @@ infrastructure for #5 and #6. This leaves #3 serialization code and #4
I/O mechanics up to a custom implementation. I/O mechanics up to a custom implementation.
This CTF debug module aims at providing a common #1 and #2 for Zephyr 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 Currently, only one CTF bottom-layer exists, POSIX ``fwrite``, but many others
are possible: are possible:
@ -82,7 +82,7 @@ are possible:
In fact, I/O varies greatly from system to system. Therefore, it is 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 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. 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_FIELDS``: Var-args of fields. May process each field with ``MAP``
- ``CTF_BOTTOM_TIMESTAMPED_INTERNALLY``: Tells where timestamping is done - ``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. very low-overhead tracing infrastructure.
CTF Middle-Layer Example CTF Top-Layer Example
========================= =========================
The CTF_EVENT macro will serialize each argument to a field:: The CTF_EVENT macro will serialize each argument to a field::
/* Example for illustration */ /* 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_EVENT(
CTF_LITERAL(u8_t, 42), CTF_LITERAL(u8_t, 42),
@ -170,11 +170,11 @@ See also the presentation by Ericsson,
Future LTTng Inspiration 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. and needlessly copied from Zephyr's Segger SystemView debug module.
For an OS like Zephyr, it would make sense to draw inspiration from 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 Doing this would enable direct reuse of TraceCompass' canned analyses
for Linux. Alternatively, LTTng-analyses in TraceCompass could be for Linux. Alternatively, LTTng-analyses in TraceCompass could be
customized to Zephyr. It is ongoing work to enable TraceCompass customized to Zephyr. It is ongoing work to enable TraceCompass

View file

@ -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 <stddef.h>
#include <string.h>
#include <ctf_bottom.h>
/* 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 */

View file

@ -7,8 +7,6 @@
#include <zephyr.h> #include <zephyr.h>
#include <kernel_structs.h> #include <kernel_structs.h>
#include <init.h> #include <init.h>
#include <ctf_middle.h>
#include "ctf_top.h" #include "ctf_top.h"
@ -29,19 +27,19 @@ void sys_trace_thread_switched_out(void)
{ {
struct k_thread *thread = k_current_get(); 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) void sys_trace_thread_switched_in(void)
{ {
struct k_thread *thread = k_current_get(); 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) void sys_trace_thread_priority_set(struct k_thread *thread)
{ {
ctf_middle_thread_priority_set((u32_t)(uintptr_t)thread, ctf_top_thread_priority_set((u32_t)(uintptr_t)thread,
thread->base.prio); thread->base.prio);
} }
@ -57,14 +55,14 @@ void sys_trace_thread_create(struct k_thread *thread)
} }
#endif #endif
ctf_middle_thread_create( ctf_top_thread_create(
(u32_t)(uintptr_t)thread, (u32_t)(uintptr_t)thread,
thread->base.prio, thread->base.prio,
name name
); );
#if defined(CONFIG_THREAD_STACK_INFO) #if defined(CONFIG_THREAD_STACK_INFO)
ctf_middle_thread_info( ctf_top_thread_info(
(u32_t)(uintptr_t)thread, (u32_t)(uintptr_t)thread,
thread->stack_info.size, thread->stack_info.size,
thread->stack_info.start 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) 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) 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) 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) 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) 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) void sys_trace_thread_info(struct k_thread *thread)
{ {
#if defined(CONFIG_THREAD_STACK_INFO) #if defined(CONFIG_THREAD_STACK_INFO)
ctf_middle_thread_info( ctf_top_thread_info(
(u32_t)(uintptr_t)thread, (u32_t)(uintptr_t)thread,
thread->stack_info.size, thread->stack_info.size,
thread->stack_info.start thread->stack_info.start
@ -118,7 +116,7 @@ void sys_trace_thread_name_set(struct k_thread *thread)
/* strncpy may not always null-terminate */ /* strncpy may not always null-terminate */
name.buf[sizeof(name.buf) - 1] = 0; name.buf[sizeof(name.buf) - 1] = 0;
} }
ctf_middle_thread_name_set( ctf_top_thread_name_set(
(u32_t)(uintptr_t)thread, (u32_t)(uintptr_t)thread,
name name
); );
@ -127,32 +125,32 @@ void sys_trace_thread_name_set(struct k_thread *thread)
void sys_trace_isr_enter(void) void sys_trace_isr_enter(void)
{ {
ctf_middle_isr_enter(); ctf_top_isr_enter();
} }
void sys_trace_isr_exit(void) void sys_trace_isr_exit(void)
{ {
ctf_middle_isr_exit(); ctf_top_isr_exit();
} }
void sys_trace_isr_exit_to_scheduler(void) 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) void sys_trace_idle(void)
{ {
ctf_middle_idle(); ctf_top_idle();
} }
void sys_trace_void(unsigned int id) void sys_trace_void(unsigned int id)
{ {
ctf_middle_void(id); ctf_top_void(id);
} }
void sys_trace_end_call(unsigned int id) void sys_trace_end_call(unsigned int id)
{ {
ctf_middle_end_call(id); ctf_top_end_call(id);
} }

View file

@ -7,5 +7,224 @@
#ifndef SUBSYS_DEBUG_TRACING_CTF_TOP_H #ifndef SUBSYS_DEBUG_TRACING_CTF_TOP_H
#define SUBSYS_DEBUG_TRACING_CTF_TOP_H #define SUBSYS_DEBUG_TRACING_CTF_TOP_H
#include <stddef.h>
#include <string.h>
#include <ctf_bottom.h>
/* 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 */ #endif /* SUBSYS_DEBUG_TRACING_CTF_TOP_H */