diff --git a/app/trace/trace.cpp b/app/trace/trace.cpp index 9099fd35d..d4d5a5ecd 100644 --- a/app/trace/trace.cpp +++ b/app/trace/trace.cpp @@ -149,22 +149,25 @@ print_float(const char *arg_string, float arg) } static void -print_arg(uint8_t arg_type, const char *arg_string, uint64_t arg) +print_arg(uint8_t arg_type, const char *arg_string, const void *arg) { + uint64_t value; + if (arg_string[0] == 0) { printf("%24s", ""); return; } + memcpy(&value, arg, sizeof(value)); switch (arg_type) { case SPDK_TRACE_ARG_TYPE_PTR: - print_ptr(arg_string, arg); + print_ptr(arg_string, value); break; case SPDK_TRACE_ARG_TYPE_INT: - print_uint64(arg_string, arg); + print_uint64(arg_string, value); break; case SPDK_TRACE_ARG_TYPE_STR: - print_string(arg_string, arg); + print_string(arg_string, value); break; } } @@ -176,6 +179,7 @@ print_event(struct spdk_trace_entry *e, uint64_t tsc_rate, struct spdk_trace_tpoint *d; struct object_stats *stats; float us; + size_t i, offset; d = &g_histories->flags.tpoint[e->tpoint_id]; stats = &g_stats[d->object_type]; @@ -202,7 +206,11 @@ print_event(struct spdk_trace_entry *e, uint64_t tsc_rate, printf("%-*s ", (int)sizeof(d->name), d->name); print_size(e->size); - print_arg(d->arg1_type, d->arg1_name, e->arg1); + for (i = 0, offset = 0; i < d->num_args; ++i) { + assert(offset < sizeof(e->args)); + print_arg(d->args[i].type, d->args[i].name, &e->args[offset]); + offset += d->args[i].size; + } if (d->new_object) { print_object_id(d->object_type, stats->index[e->object_id]); } else if (d->object_type != OBJECT_NONE) { @@ -215,7 +223,7 @@ print_event(struct spdk_trace_entry *e, uint64_t tsc_rate, printf("id: N/A"); } } else if (e->object_id != 0) { - print_arg(SPDK_TRACE_ARG_TYPE_PTR, "object", e->object_id); + print_arg(SPDK_TRACE_ARG_TYPE_PTR, "object", &e->object_id); } printf("\n"); } diff --git a/include/spdk/trace.h b/include/spdk/trace.h index 1ed6c8b31..06a99efc3 100644 --- a/include/spdk/trace.h +++ b/include/spdk/trace.h @@ -53,7 +53,7 @@ struct spdk_trace_entry { uint16_t poller_id; uint32_t size; uint64_t object_id; - uint64_t arg1; + uint8_t args[40]; }; /* If type changes from a uint8_t, change this value. */ @@ -80,15 +80,22 @@ struct spdk_trace_object { #define SPDK_TRACE_ARG_TYPE_PTR 1 #define SPDK_TRACE_ARG_TYPE_STR 2 +#define SPDK_TRACE_MAX_ARGS_COUNT 5 + +struct spdk_trace_argument { + char name[14]; + uint8_t type; + uint8_t size; +}; + struct spdk_trace_tpoint { - char name[24]; - uint16_t tpoint_id; - uint8_t owner_type; - uint8_t object_type; - uint8_t new_object; - uint8_t arg1_type; - uint8_t reserved; - char arg1_name[8]; + char name[24]; + uint16_t tpoint_id; + uint8_t owner_type; + uint8_t object_type; + uint8_t new_object; + uint8_t num_args; + struct spdk_trace_argument args[SPDK_TRACE_MAX_ARGS_COUNT]; }; struct spdk_trace_history { @@ -175,37 +182,24 @@ spdk_get_per_lcore_history(struct spdk_trace_histories *trace_histories, unsigne } void _spdk_trace_record(uint64_t tsc, uint16_t tpoint_id, uint16_t poller_id, - uint32_t size, uint64_t object_id, uint64_t arg1); + uint32_t size, uint64_t object_id, int num_args, ...); -/** - * Record the current trace state for tracing tpoints. Debug tool can read the - * information from shared memory to post-process the tpoint entries and display - * in a human-readable format. This function will call spdk_get_ticks() to get - * the current tsc to save in the tracepoint. - * - * \param tpoint_id Tracepoint id to record. - * \param poller_id Poller id to record. - * \param size Size to record. - * \param object_id Object id to record. - * \param arg1 Argument to record. - */ -static inline -void spdk_trace_record(uint16_t tpoint_id, uint16_t poller_id, uint32_t size, - uint64_t object_id, uint64_t arg1) -{ - /* - * Tracepoint group ID is encoded in the tpoint_id. Lower 6 bits determine the tracepoint - * within the group, the remaining upper bits determine the tracepoint group. Each - * tracepoint group has its own tracepoint mask. - */ - assert(tpoint_id < SPDK_TRACE_MAX_TPOINT_ID); - if (g_trace_histories == NULL || - !((1ULL << (tpoint_id & 0x3F)) & g_trace_histories->flags.tpoint_mask[tpoint_id >> 6])) { - return; - } +#define _spdk_trace_record_tsc(tsc, tpoint_id, poller_id, size, object_id, num_args, ...) \ + do { \ + assert(tpoint_id < SPDK_TRACE_MAX_TPOINT_ID); \ + if (g_trace_histories == NULL || \ + !((1ULL << (tpoint_id & 0x3F)) & \ + g_trace_histories->flags.tpoint_mask[tpoint_id >> 6])) { \ + break; \ + } \ + _spdk_trace_record(tsc, tpoint_id, poller_id, size, object_id, \ + num_args, ## __VA_ARGS__); \ + } while (0) - _spdk_trace_record(0, tpoint_id, poller_id, size, object_id, arg1); -} +/* Return the number of variable arguments. */ +#define spdk_trace_num_args(...) _spdk_trace_num_args(, ## __VA_ARGS__) +#define _spdk_trace_num_args(...) __spdk_trace_num_args(__VA_ARGS__, 8, 7, 6, 5, 4, 3, 2, 1, 0) +#define __spdk_trace_num_args(v, a1, a2, a3, a4, a5, a6, a7, a8, count, ...) count /** * Record the current trace state for tracing tpoints. Debug tool can read the @@ -217,25 +211,28 @@ void spdk_trace_record(uint16_t tpoint_id, uint16_t poller_id, uint32_t size, * \param poller_id Poller id to record. * \param size Size to record. * \param object_id Object id to record. - * \param arg1 Argument to record. + * \param ... Extra tracepoint arguments. The number, types, and order of the arguments + * must match the definition of the tracepoint. */ -static inline -void spdk_trace_record_tsc(uint64_t tsc, uint16_t tpoint_id, uint16_t poller_id, - uint32_t size, uint64_t object_id, uint64_t arg1) -{ - /* - * Tracepoint group ID is encoded in the tpoint_id. Lower 6 bits determine the tracepoint - * within the group, the remaining upper bits determine the tracepoint group. Each - * tracepoint group has its own tracepoint mask. - */ - assert(tpoint_id < SPDK_TRACE_MAX_TPOINT_ID); - if (g_trace_histories == NULL || - !((1ULL << (tpoint_id & 0x3F)) & g_trace_histories->flags.tpoint_mask[tpoint_id >> 6])) { - return; - } +#define spdk_trace_record_tsc(tsc, tpoint_id, poller_id, size, object_id, ...) \ + _spdk_trace_record_tsc(tsc, tpoint_id, poller_id, size, object_id, \ + spdk_trace_num_args(__VA_ARGS__), ## __VA_ARGS__) - _spdk_trace_record(tsc, tpoint_id, poller_id, size, object_id, arg1); -} +/** + * Record the current trace state for tracing tpoints. Debug tool can read the + * information from shared memory to post-process the tpoint entries and display + * in a human-readable format. This macro will call spdk_get_ticks() to get + * the current tsc to save in the tracepoint. + * + * \param tpoint_id Tracepoint id to record. + * \param poller_id Poller id to record. + * \param size Size to record. + * \param object_id Object id to record. + * \param ... Extra tracepoint arguments. The number, types, and order of the arguments + * must match the definition of the tracepoint. + */ +#define spdk_trace_record(tpoint_id, poller_id, size, object_id, ...) \ + spdk_trace_record_tsc(0, tpoint_id, poller_id, size, object_id, ## __VA_ARGS__) /** * Get the current tpoint mask of the given tpoint group. @@ -326,7 +323,7 @@ void spdk_trace_register_owner(uint8_t type, char id_prefix); void spdk_trace_register_object(uint8_t type, char id_prefix); /** - * Register the description for the tpoint. + * Register the description for a tpoint with a single argument. * * \param name Name for the tpoint. * \param tpoint_id Id for the tpoint. @@ -340,6 +337,29 @@ void spdk_trace_register_description(const char *name, uint16_t tpoint_id, uint8 uint8_t object_type, uint8_t new_object, uint8_t arg1_type, const char *arg1_name); +struct spdk_trace_tpoint_opts { + const char *name; + uint16_t tpoint_id; + uint8_t owner_type; + uint8_t object_type; + uint8_t new_object; + struct { + const char *name; + uint8_t type; + uint8_t size; + } args[SPDK_TRACE_MAX_ARGS_COUNT]; +}; + +/** + * Register the description for a number of tpoints. This function allows the user to register + * tracepoints with multiple arguments (up to 5). + * + * \param opts Array of structures describing tpoints and their arguments. + * \param num_opts Number of tpoints to register (size of the opts array). + */ +void spdk_trace_register_description_ext(const struct spdk_trace_tpoint_opts *opts, + size_t num_opts); + struct spdk_trace_register_fn *spdk_trace_get_first_register_fn(void); struct spdk_trace_register_fn *spdk_trace_get_next_register_fn(struct spdk_trace_register_fn diff --git a/lib/trace/Makefile b/lib/trace/Makefile index 43e221f39..75c4f3460 100644 --- a/lib/trace/Makefile +++ b/lib/trace/Makefile @@ -34,7 +34,7 @@ SPDK_ROOT_DIR := $(abspath $(CURDIR)/../..) include $(SPDK_ROOT_DIR)/mk/spdk.common.mk -SO_VER := 3 +SO_VER := 4 SO_MINOR := 0 C_SRCS = trace.c trace_flags.c trace_rpc.c diff --git a/lib/trace/spdk_trace.map b/lib/trace/spdk_trace.map index 14a03b337..303863f71 100644 --- a/lib/trace/spdk_trace.map +++ b/lib/trace/spdk_trace.map @@ -15,6 +15,7 @@ spdk_trace_register_owner; spdk_trace_register_object; spdk_trace_register_description; + spdk_trace_register_description_ext; spdk_trace_get_first_register_fn; spdk_trace_get_next_register_fn; spdk_trace_enable_tpoint_group; diff --git a/lib/trace/trace.c b/lib/trace/trace.c index 621c52aae..bf9cf4b6e 100644 --- a/lib/trace/trace.c +++ b/lib/trace/trace.c @@ -47,12 +47,14 @@ struct spdk_trace_histories *g_trace_histories; void _spdk_trace_record(uint64_t tsc, uint16_t tpoint_id, uint16_t poller_id, uint32_t size, - uint64_t object_id, uint64_t arg1) + uint64_t object_id, int num_args, ...) { struct spdk_trace_history *lcore_history; struct spdk_trace_entry *next_entry; - unsigned lcore; - uint64_t next_circular_entry; + struct spdk_trace_tpoint *tpoint; + unsigned lcore, i, offset; + uint64_t value, next_circular_entry; + va_list vl; lcore = spdk_env_get_current_core(); if (lcore >= SPDK_TRACE_MAX_LCORE) { @@ -74,7 +76,26 @@ _spdk_trace_record(uint64_t tsc, uint16_t tpoint_id, uint16_t poller_id, uint32_ next_entry->poller_id = poller_id; next_entry->size = size; next_entry->object_id = object_id; - next_entry->arg1 = arg1; + + tpoint = &g_trace_flags->tpoint[tpoint_id]; + /* Make sure that the number of arguments passed matches tracepoint definition. For now, + * allow passing extra arguments (which will be silently discard), as some traces that don't + * have any arguments pass 0 as an argument. Once they're fixed, change the condition to + * "!=". + */ + if (tpoint->num_args > num_args) { + assert(0 && "Unexpected number of tracepoint arguments"); + return; + } + + va_start(vl, num_args); + for (i = 0, offset = 0; i < tpoint->num_args; ++i) { + /* All values are currently passed as uint64_t */ + value = va_arg(vl, uint64_t); + memcpy(&next_entry->args[offset], &value, sizeof(value)); + offset += tpoint->args[i].size; + } + va_end(vl); /* Ensure all elements of the trace entry are visible to outside trace tools */ spdk_smp_wmb(); diff --git a/lib/trace/trace_flags.c b/lib/trace/trace_flags.c index 67bf21037..d2fefe0f2 100644 --- a/lib/trace/trace_flags.c +++ b/lib/trace/trace_flags.c @@ -277,35 +277,99 @@ spdk_trace_register_object(uint8_t type, char id_prefix) object->id_prefix = id_prefix; } -void -spdk_trace_register_description(const char *name, uint16_t tpoint_id, uint8_t owner_type, - uint8_t object_type, uint8_t new_object, - uint8_t arg1_type, const char *arg1_name) +static void +trace_register_description(const struct spdk_trace_tpoint_opts *opts) { struct spdk_trace_tpoint *tpoint; + size_t i, remaining_size, max_name_length; - assert(tpoint_id != 0); - assert(tpoint_id < SPDK_TRACE_MAX_TPOINT_ID); + assert(opts->tpoint_id != 0); + assert(opts->tpoint_id < SPDK_TRACE_MAX_TPOINT_ID); + + if (strnlen(opts->name, sizeof(tpoint->name)) == sizeof(tpoint->name)) { + SPDK_ERRLOG("name (%s) too long\n", opts->name); + } + + tpoint = &g_trace_flags->tpoint[opts->tpoint_id]; + assert(tpoint->tpoint_id == 0); + + snprintf(tpoint->name, sizeof(tpoint->name), "%s", opts->name); + tpoint->tpoint_id = opts->tpoint_id; + tpoint->object_type = opts->object_type; + tpoint->owner_type = opts->owner_type; + tpoint->new_object = opts->new_object; + + max_name_length = sizeof(tpoint->args[0].name); + remaining_size = sizeof(((struct spdk_trace_entry *)0)->args); + + for (i = 0; i < SPDK_TRACE_MAX_ARGS_COUNT; ++i) { + if (!opts->args[i].name) { + break; + } + + switch (opts->args[i].type) { + case SPDK_TRACE_ARG_TYPE_INT: + case SPDK_TRACE_ARG_TYPE_PTR: + case SPDK_TRACE_ARG_TYPE_STR: + /* For now all trace types need to be passed as uint64_t */ + assert(opts->args[i].size == sizeof(uint64_t)); + break; + default: + assert(0 && "invalid trace argument type"); + break; + } + + assert(remaining_size >= opts->args[i].size && "tpoint exceeds max size"); + remaining_size -= opts->args[i].size; + + if (strnlen(opts->args[i].name, max_name_length) == max_name_length) { + SPDK_ERRLOG("argument name (%s) is too long\n", opts->args[i].name); + } + + snprintf(tpoint->args[i].name, sizeof(tpoint->args[i].name), + "%s", opts->args[i].name); + tpoint->args[i].type = opts->args[i].type; + tpoint->args[i].size = opts->args[i].size; + } + + tpoint->num_args = i; +} + +void +spdk_trace_register_description_ext(const struct spdk_trace_tpoint_opts *opts, size_t num_opts) +{ + size_t i; if (g_trace_flags == NULL) { SPDK_ERRLOG("trace is not initialized\n"); return; } - if (strnlen(name, sizeof(tpoint->name)) == sizeof(tpoint->name)) { - SPDK_ERRLOG("name (%s) too long\n", name); + for (i = 0; i < num_opts; ++i) { + trace_register_description(&opts[i]); } +} - tpoint = &g_trace_flags->tpoint[tpoint_id]; - assert(tpoint->tpoint_id == 0); +void +spdk_trace_register_description(const char *name, uint16_t tpoint_id, uint8_t owner_type, + uint8_t object_type, uint8_t new_object, + uint8_t arg1_type, const char *arg1_name) +{ + struct spdk_trace_tpoint_opts opts = { + .name = name, + .tpoint_id = tpoint_id, + .owner_type = owner_type, + .object_type = object_type, + .new_object = new_object, + .args = {{ + .name = arg1_name, + .type = arg1_type, + .size = sizeof(uint64_t) + } + } + }; - snprintf(tpoint->name, sizeof(tpoint->name), "%s", name); - tpoint->tpoint_id = tpoint_id; - tpoint->object_type = object_type; - tpoint->owner_type = owner_type; - tpoint->new_object = new_object; - tpoint->arg1_type = arg1_type; - snprintf(tpoint->arg1_name, sizeof(tpoint->arg1_name), "%s", arg1_name); + spdk_trace_register_description_ext(&opts, 1); } void