From 9b51e3e9abb788e7d360529a614136fd71e5b6fe Mon Sep 17 00:00:00 2001 From: ArturX Kloniecki Date: Wed, 10 Oct 2018 09:40:46 +0200 Subject: [PATCH 1/2] debugability: Add possibility to use up to 4 params in log messages. Signed-off-by: ArturX Kloniecki --- src/include/sof/trace.h | 17 ++++- src/lib/trace.c | 140 ++++++++++++++++++++++++++++++++++++++++ 2 files changed, 155 insertions(+), 2 deletions(-) diff --git a/src/include/sof/trace.h b/src/include/sof/trace.h index 323a7be2ae0c..8aacabf8e1f4 100644 --- a/src/include/sof/trace.h +++ b/src/include/sof/trace.h @@ -111,6 +111,15 @@ void _trace_event_atomic3(uint32_t log_entry, uint32_t param1, uint32_t param2, void _trace_event_mbox_atomic3(uint32_t log_entry, uint32_t param1, uint32_t param2, uint32_t param3); +void _trace_event4(uint32_t log_entry, uint32_t param1, uint32_t param2, + uint32_t param3, uint32_t param4); +void _trace_event_mbox4(uint32_t log_entry, uint32_t param1, uint32_t param2, + uint32_t param3, uint32_t param4); +void _trace_event_atomic4(uint32_t log_entry, uint32_t param1, uint32_t param2, + uint32_t param3, uint32_t param4); +void _trace_event_mbox_atomic4(uint32_t log_entry, uint32_t param1, + uint32_t param2, uint32_t param3, uint32_t param4); + void trace_flush(void); void trace_off(void); void trace_init(struct sof *sof); @@ -124,8 +133,9 @@ void trace_init(struct sof *sof); * It comes in 2 main flavours, atomic and non-atomic. Depending of definitions * above, it might also propagate log messages to mbox if desired. * - * First argument is always class of event being logged, as defined above. - * Second argument is string literal in printf format, followed by up to 3 + * First argument is always class of event being logged, as defined in + * uapi/logging.h. + * Second argument is string literal in printf format, followed by up to 4 * parameters (uint32_t), that are used to expand into string fromat when * parsing log data. * @@ -232,6 +242,9 @@ typedef void(*log_func)(); } else if (PP_NARG(__VA_ARGS__) == 3) { \ log_function = (log_func)&function_name##3; \ log_function(entry, ##__VA_ARGS__); \ + } else if (PP_NARG(__VA_ARGS__) == 4) { \ + log_function = (log_func)&function_name##4; \ + log_function(entry, ##__VA_ARGS__); \ } \ } diff --git a/src/lib/trace.c b/src/lib/trace.c index 40ef2c014b2d..c5efe988d317 100644 --- a/src/lib/trace.c +++ b/src/lib/trace.c @@ -558,6 +558,146 @@ void _trace_event_mbox_atomic3(uint32_t log_entry, uint32_t param1, sizeof(uint32_t) * message_size_dwords); } +/* send trace events only to the local trace buffer */ +void _trace_event4(uint32_t log_entry, uint32_t param1, uint32_t param2, + uint32_t param3, uint32_t param4) +{ + uint32_t message_size_dwords = MESSAGE_SIZE(4); + uint32_t payload_offset = sizeof(struct log_entry_header) + / sizeof(uint32_t); + uint32_t dt[MESSAGE_SIZE(4)]; + + if (!trace->enable) + return; + + put_header(dt, platform_timer_get(platform_timer)); + + dt[payload_offset] = log_entry; + dt[payload_offset + 1] = param1; + dt[payload_offset + 2] = param2; + dt[payload_offset + 3] = param3; + dt[payload_offset + 4] = param4; + dtrace_event((const char *)dt, sizeof(uint32_t) * message_size_dwords); +} + +void _trace_event_atomic4(uint32_t log_entry, uint32_t param1, uint32_t param2, + uint32_t param3, uint32_t param4) +{ + uint32_t message_size_dwords = MESSAGE_SIZE(4); + uint32_t payload_offset = sizeof(struct log_entry_header) + / sizeof(uint32_t); + uint32_t dt[MESSAGE_SIZE(4)]; + + if (!trace->enable) + return; + + put_header(dt, platform_timer_get(platform_timer)); + + dt[payload_offset] = log_entry; + dt[payload_offset + 1] = param1; + dt[payload_offset + 2] = param2; + dt[payload_offset + 3] = param3; + dt[payload_offset + 4] = param4; + dtrace_event_atomic((const char *)dt, + sizeof(uint32_t) * message_size_dwords); +} + +/* send trace events to the local trace buffer and the mailbox */ +void _trace_event_mbox4(uint32_t log_entry, uint32_t param1, uint32_t param2, + uint32_t param3, uint32_t param4) +{ + unsigned long flags; + uint32_t message_size_dwords = MESSAGE_SIZE(4); + uint32_t payload_offset = sizeof(struct log_entry_header) + / sizeof(uint32_t); + uint32_t dt[MESSAGE_SIZE(4)]; + uint64_t time; + + volatile uint32_t *t; + + if (!trace->enable) + return; + + time = platform_timer_get(platform_timer); + + put_header(dt, time); + + dt[payload_offset] = log_entry; + dt[payload_offset + 1] = param1; + dt[payload_offset + 2] = param2; + dt[payload_offset + 3] = param3; + dt[payload_offset + 4] = param4; + dtrace_event((const char *)dt, sizeof(uint32_t) * message_size_dwords); + + /* send event by mail box too. */ + spin_lock_irq(&trace->lock, flags); + + /* write timestamp and event to trace buffer */ + t = (volatile uint32_t *)(MAILBOX_TRACE_BASE + trace->pos); + trace->pos += sizeof(uint32_t) * message_size_dwords; + + if (trace->pos > MAILBOX_TRACE_SIZE + - sizeof(uint32_t) * message_size_dwords) + trace->pos = 0; + + spin_unlock_irq(&trace->lock, flags); + + put_header(t, time); + t[payload_offset] = log_entry; + t[payload_offset + 1] = param1; + t[payload_offset + 2] = param2; + t[payload_offset + 3] = param3; + t[payload_offset + 4] = param4; + + /* writeback trace data */ + dcache_writeback_region((void *)t, + sizeof(uint32_t) * message_size_dwords); +} + +void _trace_event_mbox_atomic4(uint32_t log_entry, uint32_t param1, + uint32_t param2, uint32_t param3, uint32_t param4) +{ + volatile uint32_t *t; + uint32_t message_size_dwords = MESSAGE_SIZE(4); + uint32_t payload_offset = sizeof(struct log_entry_header) + / sizeof(uint32_t); + uint32_t dt[MESSAGE_SIZE(4)]; + uint64_t time; + + if (!trace->enable) + return; + + time = platform_timer_get(platform_timer); + + put_header(dt, time); + dt[payload_offset] = log_entry; + dt[payload_offset + 1] = param1; + dt[payload_offset + 2] = param2; + dt[payload_offset + 3] = param3; + dt[payload_offset + 4] = param4; + dtrace_event_atomic((const char *)dt, + sizeof(uint32_t) * message_size_dwords); + + /* write timestamp and event to trace buffer */ + t = (volatile uint32_t *)(MAILBOX_TRACE_BASE + trace->pos); + trace->pos += sizeof(uint32_t) * message_size_dwords; + + if (trace->pos > MAILBOX_TRACE_SIZE + - sizeof(uint32_t) * message_size_dwords) + trace->pos = 0; + + put_header(t, time); + t[payload_offset] = log_entry; + t[payload_offset + 1] = param1; + t[payload_offset + 2] = param2; + t[payload_offset + 3] = param3; + t[payload_offset + 4] = param4; + + /* writeback trace data */ + dcache_writeback_region((void *)t, + sizeof(uint32_t) * message_size_dwords); +} + void trace_flush(void) { volatile uint64_t *t; From f7079f5d9af369d32b415085eea571dc3af4c26a Mon Sep 17 00:00:00 2001 From: ArturX Kloniecki Date: Wed, 10 Oct 2018 11:04:44 +0200 Subject: [PATCH 2/2] debugability: Protect against invalid param num in trace_event macro Introduce STATIC_ASSERT macro for compile-time verifications. Signed-off-by: ArturX Kloniecki --- src/include/sof/sof.h | 6 ++++++ src/include/sof/trace.h | 41 ++++++++++++++++++++++------------------- 2 files changed, 28 insertions(+), 19 deletions(-) diff --git a/src/include/sof/sof.h b/src/include/sof/sof.h index 22b7a1d745a0..4047420974c2 100644 --- a/src/include/sof/sof.h +++ b/src/include/sof/sof.h @@ -48,6 +48,12 @@ struct sa; #define PP_NARG(...) (sizeof((unsigned int[]){0, ##__VA_ARGS__}) \ / sizeof(unsigned int) - 1) +/* compile-time assertion */ +#define STATIC_ASSERT(COND, MESSAGE) \ + __attribute__((unused)) \ + typedef char assertion_failed_##MESSAGE[(COND) ? 1 : -1] + + /* general firmware context */ struct sof { /* init data */ diff --git a/src/include/sof/trace.h b/src/include/sof/trace.h index 8aacabf8e1f4..4ce04a8b9f4a 100644 --- a/src/include/sof/trace.h +++ b/src/include/sof/trace.h @@ -227,25 +227,28 @@ typedef void(*log_func)(); format \ } -#define BASE_LOG(function_name, entry, ...) \ -{ \ - log_func log_function = NULL; \ - if (PP_NARG(__VA_ARGS__) == 0) { \ - log_function = (log_func)&function_name##0; \ - log_function(entry, ##__VA_ARGS__); \ - } else if (PP_NARG(__VA_ARGS__) == 1) { \ - log_function = (log_func)&function_name##1; \ - log_function(entry, ##__VA_ARGS__); \ - } else if (PP_NARG(__VA_ARGS__) == 2) { \ - log_function = (log_func)&function_name##2; \ - log_function(entry, ##__VA_ARGS__); \ - } else if (PP_NARG(__VA_ARGS__) == 3) { \ - log_function = (log_func)&function_name##3; \ - log_function(entry, ##__VA_ARGS__); \ - } else if (PP_NARG(__VA_ARGS__) == 4) { \ - log_function = (log_func)&function_name##4; \ - log_function(entry, ##__VA_ARGS__); \ - } \ +#define BASE_LOG(function_name, entry, ...) \ +{ \ + log_func log_function = NULL; \ + if (PP_NARG(__VA_ARGS__) == 0) { \ + log_function = (log_func)&function_name##0; \ + log_function(entry, ##__VA_ARGS__); \ + } else if (PP_NARG(__VA_ARGS__) == 1) { \ + log_function = (log_func)&function_name##1; \ + log_function(entry, ##__VA_ARGS__); \ + } else if (PP_NARG(__VA_ARGS__) == 2) { \ + log_function = (log_func)&function_name##2; \ + log_function(entry, ##__VA_ARGS__); \ + } else if (PP_NARG(__VA_ARGS__) == 3) { \ + log_function = (log_func)&function_name##3; \ + log_function(entry, ##__VA_ARGS__); \ + } else if (PP_NARG(__VA_ARGS__) == 4) { \ + log_function = (log_func)&function_name##4; \ + log_function(entry, ##__VA_ARGS__); \ + } else { \ + STATIC_ASSERT(PP_NARG(__VA_ARGS__) <= 4, \ + unsupported_amount_of_params_in_trace_event); \ + } \ } #define __log_message(func_name, lvl, comp_id, format, ...) \