/* Cesar project {{{ * * Copyright (C) 2007 Spidcom * * <<>> * * }}} */ /** * \file lib/src/trace.c * \brief Trace system. * \ingroup lib */ #include "common/std.h" #include "lib/trace.h" #include "hal/arch/arch.h" #include "hal/arch/io.h" #include #define TRACE_ALIGN (sizeof (u32)) #define TRACE_DEBUG_ARGS 0 /** Trace system context. */ struct trace_t { /** List of buffers. */ list_t buffers; }; static trace_t trace_global; void trace_init (void) { trace_t * const ctx = &trace_global; list_init (&ctx->buffers); #if CONFIG_TRACE_ON_FATAL dbg_assert (!dbg_fatal_cb[0]); dbg_fatal_cb[0] = trace_dbg_dump_all; #endif } void trace_uninit (void) { trace_t * const ctx = &trace_global; dbg_assert (list_empty (&ctx->buffers)); } bool trace_drop_chunks (uint n) { dbg_assert (n > 0); trace_t * const ctx = &trace_global; /* Can not help if no trace buffers. */ if (list_empty (&ctx->buffers)) return false; while (n) { /* Search the biggest buffer, taking drop level into account. */ trace_buffer_t *bigest_buf = NULL; uint bigest_buf_size = 0, second_buf_size = 0; list_node_t *i, *end; i = list_begin (&ctx->buffers); end = list_end (&ctx->buffers); for (; i != end; i = list_next (i)) { trace_buffer_t *buf = PARENT_OF (trace_buffer_t, node, i); if (!buf->locked) { uint buf_size_shifted = buf->chunks_nb > buf->preload ? (buf->chunks_nb - buf->preload) << buf->drop_level : 0; if (buf_size_shifted > bigest_buf_size) { second_buf_size = bigest_buf_size; bigest_buf_size = buf_size_shifted; bigest_buf = buf; } } } /* Drop as many block as possible to satisfy drop request. */ if (bigest_buf_size == 0) return false; uint i_can_drop = MIN (n, ((bigest_buf_size - second_buf_size + (1 << bigest_buf->drop_level) - 1) >> bigest_buf->drop_level)); trace_chunk_t *hdrop, *tdrop; hdrop = bigest_buf->head; tdrop = hdrop; n -= i_can_drop; arch_atomic_add ((int *) &bigest_buf->chunks_nb, -i_can_drop); while (--i_can_drop) tdrop = tdrop->next; bigest_buf->head = tdrop->next; blk_release_desc_range ((blk_t *) hdrop, (blk_t *) tdrop); } return true; } static int trace_format_bool (char *text, uint text_size, int data) { const char *t; uint ts; if (!data) { t = "false"; ts = 5; } else { t = "true"; ts = 4; } if (ts > text_size) return -1; else { memcpy (text, t, ts); return ts; } } static int trace_format_decimal (char *text, uint text_size, int data) { int ret = snprintf (text, text_size, "%d", data); return ret < (int) text_size ? ret : -1; } static int trace_format_unsigned (char *text, uint text_size, int data) { int ret = snprintf (text, text_size, "%u", data); return ret < (int) text_size ? ret : -1; } static int trace_format_hexa (char *text, uint text_size, int data) { int ret = snprintf (text, text_size, "0x%08x", data); return ret < (int) text_size ? ret : -1; } static const char trace_format_hexdigits[] = "0123456789abcdef"; static int trace_format_mac (char *text, uint text_size, u64 data) { const uint size = 3 * 6 - 1; if (text_size < size) return -1; else { uint i; u64 v; v = data; for (i = 5; i; i--) { *text++ = trace_format_hexdigits[(v >> 1*4) & 0xf]; *text++ = trace_format_hexdigits[(v >> 0*4) & 0xf]; *text++ = ':'; v >>= 8; } *text++ = trace_format_hexdigits[(v >> 1*4) & 0xf]; *text++ = trace_format_hexdigits[(v >> 0*4) & 0xf]; return size; } } void trace_namespace_init (trace_namespace_t *ns, const trace_event_id_t *event_ids, uint event_ids_nb) { uint i; dbg_assert (ns); for (i = 0; i < event_ids_nb; i++) dbg_assert (event_ids[i].format_string); /* Initialise fields. */ ns->event_ids = event_ids; ns->event_ids_nb = event_ids_nb; for (i = 0; i < COUNT (ns->formats); i++) ns->formats[i].size = 0; /* Provide default useful formats. */ trace_namespace_register_format (ns, 'b', trace_format_bool); trace_namespace_register_format (ns, 'd', trace_format_decimal); trace_namespace_register_format (ns, 'u', trace_format_unsigned); trace_namespace_register_format (ns, 'x', trace_format_hexa); trace_namespace_register_format_u64 (ns, 'm', trace_format_mac); } void trace_namespace_register_format (trace_namespace_t *ns, char code, trace_format_u32_t callback) { dbg_assert (ns); dbg_assert ((code >= 'A' && code <= 'Z') || (code >= 'a' && code <= 'z')); dbg_assert (callback); ns->formats[code - 'A'].callback.format_u32 = callback; ns->formats[code - 'A'].size = 1; } void trace_namespace_register_format_u64 (trace_namespace_t *ns, char code, trace_format_u64_t callback) { dbg_assert (ns); dbg_assert ((code >= 'A' && code <= 'Z') || (code >= 'a' && code <= 'z')); dbg_assert (callback); ns->formats[code - 'A'].callback.format_u64 = callback; ns->formats[code - 'A'].size = 2; } void trace_buffer_add (trace_buffer_t *buf, const char *name, uint drop_level, uint preload, bool locked, trace_namespace_t *namespace) { dbg_assert (buf); dbg_assert (name); dbg_assert (preload > 0); trace_t * const ctx = &trace_global; /* Initialise trace buffer. */ list_init_node (&buf->node); buf->chunks_nb = preload; buf->drop_level = drop_level; buf->preload = preload; buf->locked = locked && !CONFIG_TRACE_ALL_SLOW; buf->name = name; buf->namespace = namespace; /* Allocate chunks. */ blk_t *tail; buf->head = (trace_chunk_t *) blk_alloc_desc_range (preload, &tail); buf->tail = (trace_chunk_t *) tail; /* Initialise chunks. */ trace_chunk_t *i = buf->head; do { i->data_end = i->data; i->chunk_end = i->data + BLK_SIZE / TRACE_ALIGN; if (i == buf->tail) break; i = i->next; } while (1); /* Add it to context. */ list_push (&ctx->buffers, &buf->node); } void trace_buffer_remove (trace_buffer_t *buf) { dbg_assert (buf); trace_t * const ctx = &trace_global; /* Remove from context. */ list_remove (&ctx->buffers, &buf->node); /* Release chunks. */ blk_release_desc_range ((blk_t *) buf->head, (blk_t *) buf->tail); } trace_buffer_t * trace_buffer_get (const char *name) { dbg_assert (name); trace_t * const ctx = &trace_global; /* Search in list. */ list_node_t *i, *end; i = list_begin (&ctx->buffers); end = list_end (&ctx->buffers); for (; i != end; i = list_next (i)) { trace_buffer_t *buf = PARENT_OF (trace_buffer_t, node, i); if (strcmp (buf->name, name) == 0) return buf; } return NULL; } static int trace_buffer_dump_event (char *text, char *text_end, trace_namespace_t *namespace, uint **data, uint *data_end) { dbg_assert (text && text_end && text < text_end); dbg_assert (namespace); dbg_assert (data && *data && data_end && *data < data_end); /* Read event ID. */ uint id = **data; uint args = id & 0xff; id >>= 8; uint oargs = args; int *parg = (int *) *data + 1; dbg_assert (parg + args <= (int *) data_end); dbg_assert (id < namespace->event_ids_nb); const trace_event_id_t *ei = &namespace->event_ids[id]; dbg_assert (ei->format_string); char *p = text; /* Print time stamp. */ if (ei->timestamp) { dbg_assert (args); args--; int ret = snprintf (p, text_end - p, "[0x%08x] ", *parg++); if (ret >= text_end - p) return -1; p += ret; } else { int ret = snprintf (p, text_end - p, "[.] "); if (ret >= text_end - p) return -1; p += ret; } /* Decode format string. */ const char *fp; for (fp = ei->format_string; *fp; fp++) { if (*fp == '%' && *++fp != '%') { dbg_assert (((*fp >= 'A' && *fp <= 'Z') || (*fp >= 'a' && *fp <= 'z')) && namespace->formats[*fp - 'A'].size); int ret; if (namespace->formats[*fp - 'A'].size == 1) { if (TRACE_DEBUG_ARGS && !args) { if (p == text_end) return -1; *p++ = '?'; ret = 1; } else { dbg_assert (args); args--; ret = namespace->formats[*fp - 'A'].callback.format_u32 ( p, text_end - p, *parg++); } } else { if (TRACE_DEBUG_ARGS && args < 2) { if (p == text_end) return -1; *p++ = '?'; ret = 1; } else { dbg_assert (args >= 2); args -= 2; u64 arg = (u64) parg[1] << 32 | parg[0]; ret = namespace->formats[*fp - 'A'].callback.format_u64 ( p, text_end - p, arg); parg += 2; } } if (ret == -1) return -1; p += ret; } else { /* No room left, cancel the dump of this event. */ if (p == text_end) return -1; *p++ = *fp; } } dbg_assert (args == 0); /* No room left for the trailing new line, cancel the dump of this * event. */ if (p == text_end) return -1; *p++ = '\n'; *data += 1 + oargs; return p - text; } int trace_buffer_dump (trace_buffer_t *buf, trace_dump_callback_t cb, void *user) { #define DUMP_TEXT_SLACK 20 char text[2000]; int text_size = 0; trace_chunk_t *head, *tail; u32 *data, *data_end; int sum = 0; dbg_assert (buf); dbg_assert (buf->head); dbg_assert (buf->tail); dbg_assert (buf->name); dbg_assert (cb); /* Dump buffer name. */ static const char trace_start_before[] = "---trace-begin["; static const char trace_start_after[] = "]---\n"; static const char trace_stop[] = "---trace-end---\n"; uint name_len = strlen (buf->name); memcpy (text + text_size, trace_start_before, sizeof (trace_start_before) - 1); text_size += sizeof (trace_start_before) - 1; memcpy (text + text_size, buf->name, name_len); text_size += name_len; memcpy (text + text_size, trace_start_after, sizeof (trace_start_after) - 1); text_size += sizeof (trace_start_after) - 1; dbg_assert ((uint) text_size < sizeof (text) - DUMP_TEXT_SLACK); /* TODO: acquire lock, increment reference counter. */ tail = buf->tail; head = buf->head; /* Loop for each chunks. */ do { data = head->data; data_end = head->data_end; /* Loop on this chunk. */ while (data < data_end) { int ret = trace_buffer_dump_event ( text + text_size, text + COUNT (text), buf->namespace, &data, data_end); if (ret != -1) text_size += ret; if (ret == -1 || text_size + DUMP_TEXT_SLACK >= (int) COUNT (text)) { dbg_assert (text_size != 0); if (cb (user, text, text_size) != text_size) { /* Get out. */ sum = -1; break; } sum += text_size; text_size = 0; } } if (sum == -1 || head == tail) break; head = head->next; } while (1); /* Final text. */ if (sum != -1) { dbg_assert (sizeof (trace_stop) - 1 < DUMP_TEXT_SLACK); memcpy (text + text_size, trace_stop, sizeof (trace_stop) - 1); text_size += sizeof (trace_stop) - 1; if (cb (user, text, text_size) != text_size) sum = -1; else sum += text_size; } return sum; } int trace_bundle_start (const char *name, trace_dump_callback_t cb, void *user) { int name_len = 0; dbg_assert (cb); static const char bundle_start_before[] = "---trace-bundle-begin["; static const char bundle_start_after[] = "]---\n"; if (cb (user, bundle_start_before, sizeof (bundle_start_before) - 1) != sizeof (bundle_start_before) - 1) return -1; if (name) { name_len = strlen (name); if (cb (user, name, name_len) != name_len) return -1; } if (cb (user, bundle_start_after, sizeof (bundle_start_after) - 1) != sizeof (bundle_start_after) - 1) return -1; return sizeof (bundle_start_before) - 1 + sizeof (bundle_start_after) - 1 + name_len; } int trace_bundle_stop (trace_dump_callback_t cb, void *user) { dbg_assert (cb); static const char bundle_stop[] = "---trace-bundle-end---\n"; if (cb (user, bundle_stop, sizeof (bundle_stop) - 1) != sizeof (bundle_stop) - 1) return -1; return sizeof (bundle_stop) - 1; } int trace_bundle_dump_all (const char *name, trace_dump_callback_t cb, void *user) { trace_t * const ctx = &trace_global; int sum = 0, r; /* Header. */ r = trace_bundle_start (name, cb, user); if (r == -1) return -1; sum += r; /* Dump all. */ list_node_t *i, *end; i = list_begin (&ctx->buffers); end = list_end (&ctx->buffers); for (; i != end; i = list_next (i)) { trace_buffer_t *buf = PARENT_OF (trace_buffer_t, node, i); r = trace_buffer_dump (buf, cb, user); if (r == -1) return -1; sum += r; } /* Footer. */ r = trace_bundle_stop (cb, user); if (r == -1) return -1; sum += r; return sum; } static int trace_buffer_dbg_dump_callback (void *user, const char *text, uint text_size) { dbg_assert (text && text_size); arch_io_write (text, text_size); return text_size; } void trace_buffer_dbg_dump (trace_buffer_t *buf) { trace_buffer_dump (buf, trace_buffer_dbg_dump_callback, NULL); } void trace_dbg_dump_all (void) { trace_bundle_dump_all ("dbg", trace_buffer_dbg_dump_callback, NULL); } static void trace_printn_prepare (trace_buffer_t *buf, uint count) { dbg_assert (buf && buf->tail); trace_chunk_t *tail = buf->tail; if (DEBUG_MORE) dbg_assert (tail->data <= tail->data_end && tail->data_end <= tail->chunk_end); if (tail->data_end + count > tail->chunk_end) { /* No room left, allocate a new chunk. */ dbg_assert (!buf->locked); trace_chunk_t *c = (trace_chunk_t *) blk_alloc_desc (); c->data_end = c->data; c->chunk_end = c->data + BLK_SIZE / TRACE_ALIGN; tail->next = c; REORDER_BARRIER (); buf->tail = c; REORDER_BARRIER (); arch_atomic_add ((int *) &buf->chunks_nb, 1); REORDER_BARRIER (); } } void trace_print0 (trace_buffer_t *buf, uint id) { trace_printn_prepare (buf, 1); trace_fast_print0 (buf, id); } void trace_print1 (trace_buffer_t *buf, uint id, int arg0) { trace_printn_prepare (buf, 2); trace_fast_print1 (buf, id, arg0); } void trace_print2 (trace_buffer_t *buf, uint id, int arg0, int arg1) { trace_printn_prepare (buf, 3); trace_fast_print2 (buf, id, arg0, arg1); } void trace_print3 (trace_buffer_t *buf, uint id, int arg0, int arg1, int arg2) { trace_printn_prepare (buf, 4); trace_fast_print3 (buf, id, arg0, arg1, arg2); } void trace_print4 (trace_buffer_t *buf, uint id, int arg0, int arg1, int arg2, int arg3) { trace_printn_prepare (buf, 5); trace_fast_print4 (buf, id, arg0, arg1, arg2, arg3); } void trace_print5 (trace_buffer_t *buf, uint id, int arg0, int arg1, int arg2, int arg3, int arg4) { trace_printn_prepare (buf, 6); trace_fast_print5 (buf, id, arg0, arg1, arg2, arg3, arg4); } void trace_print6 (trace_buffer_t *buf, uint id, int arg0, int arg1, int arg2, int arg3, int arg4, int arg5) { trace_printn_prepare (buf, 7); trace_fast_print6 (buf, id, arg0, arg1, arg2, arg3, arg4, arg5); } void trace_print7 (trace_buffer_t *buf, uint id, int arg0, int arg1, int arg2, int arg3, int arg4, int arg5, int arg6) { trace_printn_prepare (buf, 8); trace_fast_print7 (buf, id, arg0, arg1, arg2, arg3, arg4, arg5, arg6); } void trace_print8 (trace_buffer_t *buf, uint id, int arg0, int arg1, int arg2, int arg3, int arg4, int arg5, int arg6, int arg7) { trace_printn_prepare (buf, 9); trace_fast_print8 (buf, id, arg0, arg1, arg2, arg3, arg4, arg5, arg6, arg7); } static inline u32 * trace_fast_printn_prepare (trace_buffer_t *buf, uint count) { /* Fast may become slow on request. */ if (CONFIG_TRACE_ALL_SLOW) trace_printn_prepare (buf, count); /* "Fast" means no allocation. */ if (DEBUG_MORE) dbg_assert (buf && buf->tail); trace_chunk_t *tail = buf->tail; if (DEBUG_MORE) dbg_assert (tail->data <= tail->data_end && tail->data_end <= tail->chunk_end); u32 *data_end = tail->data_end; if (data_end + count > tail->chunk_end) { /* No room left, use the oldest chunk for the new chunk. */ if (DEBUG_MORE) dbg_assert (buf->head && buf->locked); trace_chunk_t *head = buf->head; tail->next = head; buf->tail = head; buf->head = head->next; tail = head; data_end = tail->data; tail->data_end = data_end; tail->chunk_end = data_end + BLK_SIZE / TRACE_ALIGN; } /* Dump to buffer. */ return data_end; } void ARCH_ILRAM trace_fast_print0 (trace_buffer_t *buf, uint id) { u32 *p = trace_fast_printn_prepare (buf, 1); *p++ = id << 8 | 0; trace_chunk_t *tail = buf->tail; REORDER_BARRIER (); tail->data_end = p; } void ARCH_ILRAM trace_fast_print1 (trace_buffer_t *buf, uint id, int arg0) { u32 *p = trace_fast_printn_prepare (buf, 2); *p++ = id << 8 | 1; *p++ = arg0; trace_chunk_t *tail = buf->tail; REORDER_BARRIER (); tail->data_end = p; } void ARCH_ILRAM trace_fast_print2 (trace_buffer_t *buf, uint id, int arg0, int arg1) { u32 *p = trace_fast_printn_prepare (buf, 3); *p++ = id << 8 | 2; *p++ = arg0; *p++ = arg1; trace_chunk_t *tail = buf->tail; REORDER_BARRIER (); tail->data_end = p; } void ARCH_ILRAM trace_fast_print3 (trace_buffer_t *buf, uint id, int arg0, int arg1, int arg2) { u32 *p = trace_fast_printn_prepare (buf, 4); *p++ = id << 8 | 3; *p++ = arg0; *p++ = arg1; *p++ = arg2; trace_chunk_t *tail = buf->tail; REORDER_BARRIER (); tail->data_end = p; } void ARCH_ILRAM trace_fast_print4 (trace_buffer_t *buf, uint id, int arg0, int arg1, int arg2, int arg3) { u32 *p = trace_fast_printn_prepare (buf, 5); *p++ = id << 8 | 4; *p++ = arg0; *p++ = arg1; *p++ = arg2; *p++ = arg3; trace_chunk_t *tail = buf->tail; REORDER_BARRIER (); tail->data_end = p; } void ARCH_ILRAM trace_fast_print5 (trace_buffer_t *buf, uint id, int arg0, int arg1, int arg2, int arg3, int arg4) { u32 *p = trace_fast_printn_prepare (buf, 6); *p++ = id << 8 | 5; *p++ = arg0; *p++ = arg1; *p++ = arg2; *p++ = arg3; *p++ = arg4; trace_chunk_t *tail = buf->tail; REORDER_BARRIER (); tail->data_end = p; } void ARCH_ILRAM trace_fast_print6 (trace_buffer_t *buf, uint id, int arg0, int arg1, int arg2, int arg3, int arg4, int arg5) { u32 *p = trace_fast_printn_prepare (buf, 7); *p++ = id << 8 | 6; *p++ = arg0; *p++ = arg1; *p++ = arg2; *p++ = arg3; *p++ = arg4; *p++ = arg5; trace_chunk_t *tail = buf->tail; REORDER_BARRIER (); tail->data_end = p; } void ARCH_ILRAM trace_fast_print7 (trace_buffer_t *buf, uint id, int arg0, int arg1, int arg2, int arg3, int arg4, int arg5, int arg6) { u32 *p = trace_fast_printn_prepare (buf, 8); *p++ = id << 8 | 7; *p++ = arg0; *p++ = arg1; *p++ = arg2; *p++ = arg3; *p++ = arg4; *p++ = arg5; *p++ = arg6; trace_chunk_t *tail = buf->tail; REORDER_BARRIER (); tail->data_end = p; } void ARCH_ILRAM trace_fast_print8 (trace_buffer_t *buf, uint id, int arg0, int arg1, int arg2, int arg3, int arg4, int arg5, int arg6, int arg7) { u32 *p = trace_fast_printn_prepare (buf, 9); *p++ = id << 8 | 8; *p++ = arg0; *p++ = arg1; *p++ = arg2; *p++ = arg3; *p++ = arg4; *p++ = arg5; *p++ = arg6; *p++ = arg7; trace_chunk_t *tail = buf->tail; REORDER_BARRIER (); tail->data_end = p; }