From fd4c75721edbddec15fc70ef7aa786c24f2ee4f0 Mon Sep 17 00:00:00 2001 From: Liu Xiaodong Date: Tue, 13 Nov 2018 12:23:16 -0500 Subject: [PATCH] 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 " Change-Id: I855ce6b4f14a716dcdd9078913da5ea8e577af3a Signed-off-by: Liu Xiaodong Reviewed-on: https://review.gerrithub.io/433099 Chandler-Test-Pool: SPDK Automated Test System Reviewed-by: Jim Harris Reviewed-by: Shuhei Matsumoto Tested-by: SPDK CI Jenkins --- app/iscsi_top/iscsi_top.cpp | 4 +-- app/trace/trace.cpp | 40 ++++++++++++++++++------- include/spdk/event.h | 3 ++ include/spdk/trace.h | 59 ++++++++++++++++++++++++++++++------- lib/event/app.c | 16 +++++++++- lib/trace/trace.c | 24 +++++++++------ 6 files changed, 112 insertions(+), 34 deletions(-) diff --git a/app/iscsi_top/iscsi_top.cpp b/app/iscsi_top/iscsi_top.cpp index 50449b596..ba59bfdab 100644 --- a/app/iscsi_top/iscsi_top.cpp +++ b/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) { diff --git a/app/trace/trace.cpp b/app/trace/trace.cpp index ed3f2a8f9..d17e2d5a1 100644 --- a/app/trace/trace.cpp +++ b/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); diff --git a/include/spdk/event.h b/include/spdk/event.h index c1364b0e3..4d195062b 100644 --- a/include/spdk/event.h +++ b/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 { diff --git a/include/spdk/trace.h b/include/spdk/trace.h index 94cae1755..2bbc6b1a4 100644 --- a/include/spdk/trace.h +++ b/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. diff --git a/lib/event/app.c b/lib/event/app.c index 519604e89..0bb771aa6 100644 --- a/lib/event/app.c +++ b/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 \n"); printf(" pci addr to whitelist (-B and -W cannot be used at the same time)\n"); printf(" --huge-dir use a specific hugetlbfs mount to reserve memory from\n"); + printf(" --num-trace-entries 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 diff --git a/lib/trace/trace.c b/lib/trace/trace.c index 8981bcbd7..e31f52d93 100644 --- a/lib/trace/trace.c +++ b/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;