Commit f301d156 authored by Konrad Sztyber's avatar Konrad Sztyber Committed by Jim Harris
Browse files

lib/trace: variable number of tracepoint arguments 



This patch allows tracepoint to record a variable number of arugments.
An additional function has been added,
`spdk_trace_register_description_ext()`, which allows the user to
register definitions for tracepoints specifying all the arugments that
they accept.  Users can also call `spdk_trace_register_description()` to
register tpoints with a single argument (or none).

Currently, all of the tracepoint arguments need to be passed as
uint64_t.

The trace record functions use variable arguments and rely on tracepoint
description to know the order and the format of the arguments passed.
That means that the user needs to take care that they're always in sync.

Moreover, this patch extends the tracepoint entry size from 32B to 64B,
meaning that there are 40B that can be utilized for passing arguments,
which in turn means that there can be up to 5 arguments per tracepoint.

Signed-off-by: default avatarKonrad Sztyber <konrad.sztyber@intel.com>
Change-Id: I9993eabb2663078052439320e6d2f6ae607a47ff
Reviewed-on: https://review.spdk.io/gerrit/c/spdk/spdk/+/7956


Tested-by: default avatarSPDK CI Jenkins <sys_sgci@intel.com>
Reviewed-by: default avatarAleksey Marchuk <alexeymar@mellanox.com>
Reviewed-by: default avatarJim Harris <james.r.harris@intel.com>
Community-CI: Mellanox Build Bot
parent 1be9c295

app/trace/trace.cpp

+14 −6
Original line number Diff line number Diff line
@@ -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");

}

include/spdk/trace.h

+71 −51
Original line number Diff line number Diff line
@@ -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];

	uint8_t				num_args;

	struct spdk_trace_argument	args[SPDK_TRACE_MAX_ARGS_COUNT];

};



struct spdk_trace_history {
@@ -175,67 +182,57 @@ 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, ...);



#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)



/* 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

 * 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.

 * in a human-readable format.

 *

 * \param tsc Current tsc.

 * \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.

 * \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(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;

	}



	_spdk_trace_record(0, tpoint_id, poller_id, size, object_id, arg1);

}

#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__)



/**

 * 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.

 * in a human-readable format. This macro will call spdk_get_ticks() to get

 * the current tsc to save in the tracepoint.

 *

 * \param tsc Current tsc.

 * \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.

 * \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;

	}



	_spdk_trace_record(tsc, tpoint_id, poller_id, size, object_id, arg1);

}

#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

lib/trace/Makefile

+1 −1
Original line number Diff line number Diff line
@@ -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

lib/trace/spdk_trace.map

+1 −0
Original line number Diff line number Diff line
@@ -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;

lib/trace/trace.c

+25 −4
Original line number Diff line number Diff line
@@ -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();