lib/trace: set num-trace-entries by app param

Number of trace entries in circular buffer per lcore can be
assigned by the boot parameter of SPDK app with
"--num-trace-entries <NUM>"

Change-Id: I855ce6b4f14a716dcdd9078913da5ea8e577af3a
Signed-off-by: Liu Xiaodong <xiaodong.liu@intel.com>
Reviewed-on: https://review.gerrithub.io/433099
Chandler-Test-Pool: SPDK Automated Test System <sys_sgsw@intel.com>
Reviewed-by: Jim Harris <james.r.harris@intel.com>
Reviewed-by: Shuhei Matsumoto <shuhei.matsumoto.xt@hitachi.com>
Tested-by: SPDK CI Jenkins <sys_sgci@intel.com>

app/iscsi_top/iscsi_top.cpp

@@ -169,7 +169,7 @@ int main(int argc, char **argv)
 	memset(last_tasks_done, 0, sizeof(last_tasks_done));
 
 	for (i = 0; i < SPDK_TRACE_MAX_LCORE; i++) {
-		history = &histories->per_lcore_history[i];
+		history = spdk_get_per_lcore_history(histories, i, histories->flags.num_entries);
 		last_tasks_done[i] = history->tpoint_count[TRACE_ISCSI_TASK_DONE];
 	}
 
@@ -227,7 +227,7 @@ int main(int argc, char **argv)
 		printf("=============\n");
 		total_tasks_done_per_sec = 0;
 		for (i = 0; i < SPDK_TRACE_MAX_LCORE; i++) {
-			history = &histories->per_lcore_history[i];
+			history = spdk_get_per_lcore_history(histories, i, histories->flags.num_entries);
 			tasks_done = history->tpoint_count[TRACE_ISCSI_TASK_DONE];
 			tasks_done_delta = tasks_done - last_tasks_done[i];
 			if (tasks_done_delta == 0) {

app/trace/trace.cpp

@@ -210,16 +210,14 @@ process_event(struct spdk_trace_entry *e, uint64_t tsc_rate,
 }
 
 static int
-populate_events(struct spdk_trace_history *history)
+populate_events(struct spdk_trace_history *history, int num_entries)
 {
-	int i, num_entries, num_entries_filled;
+	int i, num_entries_filled;
 	struct spdk_trace_entry *e;
 	int first, last, lcore;
 
 	lcore = history->lcore;
 
-	num_entries = SPDK_COUNTOF(history->entries);
-
 	e = history->entries;
 
 	num_entries_filled = num_entries;
@@ -295,6 +293,9 @@ int main(int argc, char **argv)
 	int			op;
 	char			shm_name[64];
 	int			shm_id = -1, shm_pid = -1;
+	uint64_t		num_entries;
+	uint64_t		trace_histories_size;
+	uint64_t		lcore_history_size;
 
 	g_exe_name = argv[0];
 	while ((op = getopt(argc, argv, "c:f:i:p:qs:")) != -1) {
@@ -357,6 +358,7 @@ int main(int argc, char **argv)
 		exit(-1);
 	}
 
+	/* Map the header of trace file */
 	history_ptr = mmap(NULL, sizeof(*g_histories), PROT_READ, MAP_SHARED, fd, 0);
 	if (history_ptr == MAP_FAILED) {
 		fprintf(stderr, "Could not mmap %s.\n", file_name ? file_name : shm_name);
@@ -373,29 +375,45 @@ int main(int argc, char **argv)
 		exit(-1);
 	}
 
+	num_entries = g_histories->flags.num_entries;
+
 	if (g_verbose) {
 		printf("TSC Rate: %ju\n", g_tsc_rate);
+		printf("Number Trace Entries per lcore: %ju\n", num_entries);
 	}
 
-	history_entries = (struct spdk_trace_history *)malloc(sizeof(g_histories->per_lcore_history));
+	/* Remap the entire trace file */
+	trace_histories_size = spdk_get_trace_histories_size(num_entries);
+	munmap(history_ptr, sizeof(*g_histories));
+	history_ptr = mmap(NULL, trace_histories_size, PROT_READ, MAP_SHARED, fd, 0);
+	if (history_ptr == MAP_FAILED) {
+		fprintf(stderr, "Could not mmap shm %s.\n", shm_name);
+		usage();
+		exit(-1);
+	}
+
+	g_histories = (struct spdk_trace_histories *)history_ptr;
+
+	lcore_history_size = spdk_get_trace_history_size(num_entries);
+	history_entries = (struct spdk_trace_history *)malloc(lcore_history_size * SPDK_TRACE_MAX_LCORE);
 	if (history_entries == NULL) {
 		goto cleanup;
 	}
 	memcpy(history_entries, g_histories->per_lcore_history,
-	       sizeof(g_histories->per_lcore_history));
+	       lcore_history_size * SPDK_TRACE_MAX_LCORE);
 
 	if (lcore == SPDK_TRACE_MAX_LCORE) {
 		for (i = 0; i < SPDK_TRACE_MAX_LCORE; i++) {
-			history = &history_entries[i];
+			history = spdk_get_per_lcore_history(g_histories, i, num_entries);
 			if (history->entries[0].tsc == 0) {
 				continue;
 			}
-			populate_events(history);
+			populate_events(history, num_entries);
 		}
 	} else {
-		history = &history_entries[lcore];
+		history = spdk_get_per_lcore_history(g_histories, lcore, num_entries);
 		if (history->entries[0].tsc != 0) {
-			populate_events(history);
+			populate_events(history, num_entries);
 		}
 	}
 
@@ -410,7 +428,7 @@ int main(int argc, char **argv)
 	free(history_entries);
 
 cleanup:
-	munmap(history_ptr, sizeof(*g_histories));
+	munmap(history_ptr, trace_histories_size);
 	close(fd);
 
 	return (0);

include/spdk/event.h

@@ -122,6 +122,9 @@ struct spdk_app_opts {
 	 * when this flag is enabled.
 	 */
 	bool			delay_subsystem_init;
+
+	/* Number of trace entries allocated for each core */
+	uint64_t		num_entries;
 };
 
 struct spdk_reactor_tsc_stats {

include/spdk/trace.h

@@ -45,7 +45,7 @@
 extern "C" {
 #endif
 
-#define SPDK_TRACE_SIZE	 (32 * 1024)
+#define SPDK_DEFAULT_NUM_TRACE_ENTRIES	 (32 * 1024)
 
 struct spdk_trace_entry {
 	uint64_t	tsc;
@@ -92,14 +92,6 @@ struct spdk_trace_history {
 	/** Logical core number associated with this structure instance. */
 	int				lcore;
 
-	/**
-	 * Circular buffer of spdk_trace_entry structures for tracing
-	 *  tpoints on this core.  Debug tool spdk_trace reads this
-	 *  buffer from shared memory to post-process the tpoint entries and
-	 *  display in a human-readable format.
-	 */
-	struct spdk_trace_entry		entries[SPDK_TRACE_SIZE];
-
 	/**
 	 * Running count of number of occurrences of each tracepoint on this
 	 *  lcore.  Debug tools can use this to easily count tracepoints such as
@@ -110,12 +102,20 @@ struct spdk_trace_history {
 	/** Index to next spdk_trace_entry to fill in the circular buffer. */
 	uint32_t			next_entry;
 
+	/**
+	 * Circular buffer of spdk_trace_entry structures for tracing
+	 *  tpoints on this core.  Debug tool spdk_trace reads this
+	 *  buffer from shared memory to post-process the tpoint entries and
+	 *  display in a human-readable format.
+	 */
+	struct spdk_trace_entry		entries[0];
 };
 
 #define SPDK_TRACE_MAX_LCORE		128
 
 struct spdk_trace_flags {
 	uint64_t			tsc_rate;
+	uint64_t			num_entries;
 	uint64_t			tpoint_mask[SPDK_TRACE_MAX_GROUP_ID];
 	struct spdk_trace_owner		owner[UCHAR_MAX + 1];
 	struct spdk_trace_object	object[UCHAR_MAX + 1];
@@ -127,9 +127,45 @@ extern struct spdk_trace_histories *g_trace_histories;
 
 struct spdk_trace_histories {
 	struct spdk_trace_flags flags;
-	struct spdk_trace_history	per_lcore_history[SPDK_TRACE_MAX_LCORE];
+
+	/**
+	 * struct spdk_trace_history has a dynamic size determined by num_entries
+	 * in spdk_trace_init. Mark array size of per_lcore_history to be 0 in uint8_t
+	 * as a reminder that each per_lcore_history pointer should be gotten by
+	 * proper API, instead of directly referencing by struct element.
+	 */
+	uint8_t	per_lcore_history[0];
 };
 
+static inline uint64_t
+spdk_get_trace_history_size(uint64_t num_entries)
+{
+	return sizeof(struct spdk_trace_history) + num_entries * sizeof(struct spdk_trace_entry);
+}
+
+static inline uint64_t
+spdk_get_trace_histories_size(uint64_t num_entries)
+{
+	int size;
+
+	size = sizeof(struct spdk_trace_flags);
+	size += spdk_get_trace_history_size(num_entries) * SPDK_TRACE_MAX_LCORE;
+
+	return size;
+}
+
+static inline struct spdk_trace_history *
+spdk_get_per_lcore_history(struct spdk_trace_histories *trace_histories, unsigned lcore,
+			   uint64_t num_entries)
+{
+	char *lcore_history_offset;
+
+	lcore_history_offset = (char *)trace_histories->per_lcore_history;
+	lcore_history_offset += lcore * spdk_get_trace_history_size(num_entries);
+
+	return (struct spdk_trace_history *)lcore_history_offset;
+}
+
 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);
 
@@ -238,9 +274,10 @@ void spdk_trace_set_tpoint_group_mask(uint64_t tpoint_group_mask);
  * human-readable format.
  *
  * \param shm_name Name of shared memory.
+ * \param num_entries Number of trace entries per lcore.
  * \return 0 on success, else non-zero indicates a failure.
  */
-int spdk_trace_init(const char *shm_name);
+int spdk_trace_init(const char *shm_name, uint64_t num_entries);
 
 /**
  * Unmap global trace memory structs.

lib/event/app.c

@@ -47,6 +47,7 @@
 #define SPDK_APP_DEFAULT_LOG_LEVEL		SPDK_LOG_NOTICE
 #define SPDK_APP_DEFAULT_LOG_PRINT_LEVEL	SPDK_LOG_INFO
 #define SPDK_APP_DEFAULT_BACKTRACE_LOG_LEVEL	SPDK_LOG_ERROR
+#define SPDK_APP_DEFAULT_NUM_TRACE_ENTRIES	SPDK_DEFAULT_NUM_TRACE_ENTRIES
 
 #define SPDK_APP_DPDK_DEFAULT_MEM_SIZE		-1
 #define SPDK_APP_DPDK_DEFAULT_MASTER_CORE	-1
@@ -115,6 +116,8 @@ static const struct option g_cmdline_options[] = {
 	{"wait-for-rpc",		no_argument,		NULL, WAIT_FOR_RPC_OPT_IDX},
 #define HUGE_DIR_OPT_IDX	259
 	{"huge-dir",			no_argument,		NULL, HUGE_DIR_OPT_IDX},
+#define NUM_TRACE_ENTRIES_OPT_IDX	260
+	{"num-trace-entries",		required_argument,	NULL, NUM_TRACE_ENTRIES_OPT_IDX},
 };
 
 /* Global section */
@@ -272,6 +275,7 @@ spdk_app_opts_init(struct spdk_app_opts *opts)
 	opts->max_delay_us = 0;
 	opts->print_level = SPDK_APP_DEFAULT_LOG_PRINT_LEVEL;
 	opts->rpc_addr = SPDK_DEFAULT_RPC_ADDR;
+	opts->num_entries = SPDK_APP_DEFAULT_NUM_TRACE_ENTRIES;
 	opts->delay_subsystem_init = false;
 }
 
@@ -518,7 +522,7 @@ spdk_app_setup_trace(struct spdk_app_opts *opts)
 		snprintf(shm_name, sizeof(shm_name), "/%s_trace.pid%d", opts->name, (int)getpid());
 	}
 
-	if (spdk_trace_init(shm_name) != 0) {
+	if (spdk_trace_init(shm_name, opts->num_entries) != 0) {
 		return -1;
 	}
 
@@ -735,6 +739,8 @@ usage(void (*app_usage)(void))
 	printf(" -W, --pci-whitelist <bdf>\n");
 	printf("                           pci addr to whitelist (-B and -W cannot be used at the same time)\n");
 	printf("      --huge-dir <path>    use a specific hugetlbfs mount to reserve memory from\n");
+	printf("      --num-trace-entries <num>   number of trace entries for each core (default %d)\n",
+	       SPDK_APP_DEFAULT_NUM_TRACE_ENTRIES);
 	spdk_tracelog_usage(stdout, "-L");
 	if (app_usage) {
 		app_usage();
@@ -929,6 +935,14 @@ spdk_app_parse_args(int argc, char **argv, struct spdk_app_opts *opts,
 		case HUGE_DIR_OPT_IDX:
 			opts->hugedir = optarg;
 			break;
+		case NUM_TRACE_ENTRIES_OPT_IDX:
+			opts->num_entries = strtoull(optarg, NULL, 0);
+			if (opts->num_entries == ULLONG_MAX || opts->num_entries == 0) {
+				fprintf(stderr, "Invalid num_entries %s\n", optarg);
+				usage(app_usage);
+				goto out;
+			}
+			break;
 		case '?':
 			/*
 			 * In the event getopt() above detects an option

lib/trace/trace.c

@@ -55,7 +55,8 @@ _spdk_trace_record(uint64_t tsc, uint16_t tpoint_id, uint16_t poller_id, uint32_
 		return;
 	}
 
-	lcore_history = &g_trace_histories->per_lcore_history[lcore];
+	lcore_history = spdk_get_per_lcore_history(g_trace_histories, lcore,
+			g_trace_histories->flags.num_entries);
 	if (tsc == 0) {
 		tsc = spdk_get_ticks();
 	}
@@ -71,15 +72,16 @@ _spdk_trace_record(uint64_t tsc, uint16_t tpoint_id, uint16_t poller_id, uint32_
 	next_entry->arg1 = arg1;
 
 	lcore_history->next_entry++;
-	if (lcore_history->next_entry == SPDK_TRACE_SIZE) {
+	if (lcore_history->next_entry == g_trace_histories->flags.num_entries) {
 		lcore_history->next_entry = 0;
 	}
 }
 
 int
-spdk_trace_init(const char *shm_name)
+spdk_trace_init(const char *shm_name, uint64_t num_entries)
 {
 	int i = 0;
+	int histories_size = spdk_get_trace_histories_size(num_entries);
 
 	snprintf(g_shm_name, sizeof(g_shm_name), "%s", shm_name);
 
@@ -90,12 +92,12 @@ spdk_trace_init(const char *shm_name)
 		return 1;
 	}
 
-	if (ftruncate(g_trace_fd, sizeof(*g_trace_histories)) != 0) {
+	if (ftruncate(g_trace_fd, histories_size) != 0) {
 		fprintf(stderr, "could not truncate shm\n");
 		goto trace_init_err;
 	}
 
-	g_trace_histories = mmap(NULL, sizeof(*g_trace_histories), PROT_READ | PROT_WRITE,
+	g_trace_histories = mmap(NULL, histories_size, PROT_READ | PROT_WRITE,
 				 MAP_SHARED, g_trace_fd, 0);
 	if (g_trace_histories == MAP_FAILED) {
 		fprintf(stderr, "could not mmap shm\n");
@@ -107,7 +109,7 @@ spdk_trace_init(const char *shm_name)
 	 * altogether.
 	 */
 #if defined(__linux__)
-	if (mlock(g_trace_histories, sizeof(*g_trace_histories)) != 0) {
+	if (mlock(g_trace_histories, histories_size) != 0) {
 		fprintf(stderr, "Could not mlock shm for tracing - %s.\n", spdk_strerror(errno));
 		if (errno == ENOMEM) {
 			fprintf(stderr, "Check /dev/shm for old tracing files that can be deleted.\n");
@@ -116,14 +118,18 @@ spdk_trace_init(const char *shm_name)
 	}
 #endif
 
-	memset(g_trace_histories, 0, sizeof(*g_trace_histories));
+	memset(g_trace_histories, 0, histories_size);
 
 	g_trace_flags = &g_trace_histories->flags;
 
 	g_trace_flags->tsc_rate = spdk_get_ticks_hz();
+	g_trace_flags->num_entries = num_entries;
 
 	for (i = 0; i < SPDK_TRACE_MAX_LCORE; i++) {
-		g_trace_histories->per_lcore_history[i].lcore = i;
+		struct spdk_trace_history *lcore_history;
+
+		lcore_history = spdk_get_per_lcore_history(g_trace_histories, i, num_entries);
+		lcore_history->lcore = i;
 	}
 
 	spdk_trace_flags_init();
@@ -132,7 +138,7 @@ spdk_trace_init(const char *shm_name)
 
 trace_init_err:
 	if (g_trace_histories != MAP_FAILED) {
-		munmap(g_trace_histories, sizeof(*g_trace_histories));
+		munmap(g_trace_histories, histories_size);
 	}
 	close(g_trace_fd);
 	g_trace_fd = -1;