diff --git a/doc/management.txt b/doc/management.txt index 1dd52f5c8..a65eeca4f 100644 --- a/doc/management.txt +++ b/doc/management.txt @@ -2674,7 +2674,8 @@ trace level [] developer it reports everything available, which can include advanced information such as "breaking out of this loop" that are only relevant to a developer trying to understand a bug that - only happens once in a while in field. + only happens once in a while in field. Function names are + only reported at this level. It is highly recommended to always use the "user" level only and switch to other levels only if instructed to do so by a developer. Also it is a good diff --git a/include/proto/trace.h b/include/proto/trace.h index 726fefdbf..9c5c11128 100644 --- a/include/proto/trace.h +++ b/include/proto/trace.h @@ -47,32 +47,44 @@ * These 4 arguments as well as the cb() function pointer may all be NULL, or * simply omitted (in which case they will be replaced by a NULL). This * ordering allows many TRACE() calls to be placed using copy-paste and just - * change the message at the beginning. + * change the message at the beginning. Only TRACE_DEVEL(), TRACE_ENTER() and + * TRACE_LEAVE() will report the calling function's name. */ #define TRACE(msg, mask, ...) \ - trace(TRACE_LEVEL, (mask), TRACE_SOURCE, ist(TRC_LOC), TRC_5ARGS(__VA_ARGS__,,,,,), ist(msg)) + trace(TRACE_LEVEL, (mask), TRACE_SOURCE, ist(TRC_LOC), NULL, TRC_5ARGS(__VA_ARGS__,,,,,), ist(msg)) #define TRACE_USER(msg, mask, ...) \ - trace(TRACE_LEVEL_USER, (mask), TRACE_SOURCE, ist(TRC_LOC), TRC_5ARGS(__VA_ARGS__,,,,,), ist(msg)) + trace(TRACE_LEVEL_USER, (mask), TRACE_SOURCE, ist(TRC_LOC), NULL, TRC_5ARGS(__VA_ARGS__,,,,,), ist(msg)) #define TRACE_DATA(msg, mask, ...) \ - trace(TRACE_LEVEL_DATA, (mask), TRACE_SOURCE, ist(TRC_LOC), TRC_5ARGS(__VA_ARGS__,,,,,), ist(msg)) + trace(TRACE_LEVEL_DATA, (mask), TRACE_SOURCE, ist(TRC_LOC), NULL, TRC_5ARGS(__VA_ARGS__,,,,,), ist(msg)) #define TRACE_PROTO(msg, mask, ...) \ - trace(TRACE_LEVEL_PROTO, (mask), TRACE_SOURCE, ist(TRC_LOC), TRC_5ARGS(__VA_ARGS__,,,,,), ist(msg)) + trace(TRACE_LEVEL_PROTO, (mask), TRACE_SOURCE, ist(TRC_LOC), NULL, TRC_5ARGS(__VA_ARGS__,,,,,), ist(msg)) #define TRACE_STATE(msg, mask, ...) \ - trace(TRACE_LEVEL_STATE, (mask), TRACE_SOURCE, ist(TRC_LOC), TRC_5ARGS(__VA_ARGS__,,,,,), ist(msg)) + trace(TRACE_LEVEL_STATE, (mask), TRACE_SOURCE, ist(TRC_LOC), NULL, TRC_5ARGS(__VA_ARGS__,,,,,), ist(msg)) #define TRACE_DEVEL(msg, mask, ...) \ - trace(TRACE_LEVEL_DEVELOPER, (mask), TRACE_SOURCE, ist(TRC_LOC), TRC_5ARGS(__VA_ARGS__,,,,,), ist(msg)) + trace(TRACE_LEVEL_DEVELOPER, (mask), TRACE_SOURCE, ist(TRC_LOC), __FUNCTION__, TRC_5ARGS(__VA_ARGS__,,,,,), ist(msg)) + +#define TRACE_ENTER(mask, ...) \ + trace(TRACE_LEVEL_DEVELOPER, (mask), TRACE_SOURCE, ist(TRC_LOC), __FUNCTION__, TRC_5ARGS(__VA_ARGS__,,,,,), ist("entering")) + +#define TRACE_LEAVE(mask, ...) \ + trace(TRACE_LEVEL_DEVELOPER, (mask), TRACE_SOURCE, ist(TRC_LOC), __FUNCTION__, TRC_5ARGS(__VA_ARGS__,,,,,), ist("leaving")) + +#define TRACE_POINT(mask, ...) \ + trace(TRACE_LEVEL_DEVELOPER, (mask), TRACE_SOURCE, ist(TRC_LOC), __FUNCTION__, TRC_5ARGS(__VA_ARGS__,,,,,), ist("in")) extern struct list trace_sources; extern THREAD_LOCAL struct buffer trace_buf; -void __trace(enum trace_level level, uint64_t mask, struct trace_source *src, const struct ist where, +void __trace(enum trace_level level, uint64_t mask, struct trace_source *src, + const struct ist where, const char *func, const void *a1, const void *a2, const void *a3, const void *a4, - void (*cb)(enum trace_level level, uint64_t mask, const struct trace_source *src, const struct ist where, + void (*cb)(enum trace_level level, uint64_t mask, const struct trace_source *src, + const struct ist where, const struct ist func, const void *a1, const void *a2, const void *a3, const void *a4), const struct ist msg); @@ -106,14 +118,16 @@ static inline void trace_register_source(struct trace_source *source) } /* sends a trace for the given source */ -static inline void trace(enum trace_level level, uint64_t mask, struct trace_source *src, const struct ist where, +static inline void trace(enum trace_level level, uint64_t mask, struct trace_source *src, + const struct ist where, const char *func, const void *a1, const void *a2, const void *a3, const void *a4, - void (*cb)(enum trace_level level, uint64_t mask, const struct trace_source *src, const struct ist where, + void (*cb)(enum trace_level level, uint64_t mask, const struct trace_source *src, + const struct ist where, const struct ist func, const void *a1, const void *a2, const void *a3, const void *a4), const struct ist msg) { if (unlikely(src->state != TRACE_STATE_STOPPED)) - __trace(level, mask, src, where, a1, a2, a3, a4, cb, msg); + __trace(level, mask, src, where, func, a1, a2, a3, a4, cb, msg); } #endif /* _PROTO_TRACE_H */ diff --git a/include/types/trace.h b/include/types/trace.h index 03eb7dbc9..91a57f88c 100644 --- a/include/types/trace.h +++ b/include/types/trace.h @@ -124,7 +124,8 @@ struct trace_source { const struct trace_event *known_events; struct list source_link; // element in list of known trace sources void (*default_cb)(enum trace_level level, uint64_t mask, - const struct trace_source *src, const struct ist where, + const struct trace_source *src, + const struct ist where, const struct ist func, const void *a1, const void *a2, const void *a3, const void *a4); uint32_t arg_def; // argument definitions (sum of TRC_ARG{1..4}_*) const struct name_desc *lockon_args; // must be 4 entries if not NULL diff --git a/src/trace.c b/src/trace.c index 7769b5d26..63ad1f9b4 100644 --- a/src/trace.c +++ b/src/trace.c @@ -69,9 +69,11 @@ static inline const void *trace_pick_arg(uint32_t arg_def, const void *a1, const } /* write a message for the given trace source */ -void __trace(enum trace_level level, uint64_t mask, struct trace_source *src, const struct ist where, +void __trace(enum trace_level level, uint64_t mask, struct trace_source *src, + const struct ist where, const char *func, const void *a1, const void *a2, const void *a3, const void *a4, - void (*cb)(enum trace_level level, uint64_t mask, const struct trace_source *src, const struct ist where, + void (*cb)(enum trace_level level, uint64_t mask, const struct trace_source *src, + const struct ist where, const struct ist func, const void *a1, const void *a2, const void *a3, const void *a4), const struct ist msg) { @@ -83,8 +85,10 @@ void __trace(enum trace_level level, uint64_t mask, struct trace_source *src, co const struct stream *strm = NULL; const struct connection *conn = NULL; const void *lockon_ptr = NULL; + struct ist ist_func = ist(func); char tnum[4]; - struct ist line[8]; + struct ist line[10]; + int words = 0; if (likely(src->state == TRACE_STATE_STOPPED)) return; @@ -177,20 +181,26 @@ void __trace(enum trace_level level, uint64_t mask, struct trace_source *src, co /* log the logging location truncated to 10 chars from the right so that * the line number and the end of the file name are there. */ - line[0] = ist("["); + line[words++] = ist("["); tnum[0] = '0' + tid / 10; tnum[1] = '0' + tid % 10; tnum[2] = '|'; tnum[3] = 0; - line[1] = ist(tnum); - line[2] = src->name; - line[3] = ist("|"); - line[4] = where; - if (line[4].len > 13) { - line[4].ptr += (line[4].len - 13); - line[4].len = 13; + line[words++] = ist(tnum); + line[words++] = src->name; + line[words++] = ist("|"); + line[words] = where; + if (line[words].len > 13) { + line[words].ptr += (line[words].len - 13); + line[words].len = 13; + } + words++; + line[words++] = ist("] "); + + if (ist_func.ptr) { + line[words++] = ist_func; + line[words++] = ist("(): "); } - line[5] = ist("] "); if (!cb) cb = src->default_cb; @@ -202,15 +212,16 @@ void __trace(enum trace_level level, uint64_t mask, struct trace_source *src, co */ b_reset(&trace_buf); b_istput(&trace_buf, msg); - cb(level, mask, src, where, a1, a2, a3, a4); - line[6].ptr = trace_buf.area; - line[6].len = trace_buf.data; + cb(level, mask, src, where, ist_func, a1, a2, a3, a4); + line[words].ptr = trace_buf.area; + line[words].len = trace_buf.data; + words++; } else - line[6] = msg; + line[words++] = msg; if (src->sink) - sink_write(src->sink, line, 7); + sink_write(src->sink, line, words); end: /* check if we need to stop the trace now */