1 /*- 2 * BSD LICENSE 3 * 4 * Copyright (c) Intel Corporation. 5 * All rights reserved. 6 * 7 * Redistribution and use in source and binary forms, with or without 8 * modification, are permitted provided that the following conditions 9 * are met: 10 * 11 * * Redistributions of source code must retain the above copyright 12 * notice, this list of conditions and the following disclaimer. 13 * * Redistributions in binary form must reproduce the above copyright 14 * notice, this list of conditions and the following disclaimer in 15 * the documentation and/or other materials provided with the 16 * distribution. 17 * * Neither the name of Intel Corporation nor the names of its 18 * contributors may be used to endorse or promote products derived 19 * from this software without specific prior written permission. 20 * 21 * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS 22 * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT 23 * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR 24 * A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT 25 * OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, 26 * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT 27 * LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, 28 * DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY 29 * THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT 30 * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE 31 * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. 32 */ 33 34 #include "spdk/stdinc.h" 35 #include "spdk/env.h" 36 #include "spdk/json.h" 37 #include "spdk/likely.h" 38 #include "spdk/string.h" 39 #include "spdk/util.h" 40 41 #include <map> 42 43 extern "C" { 44 #include "spdk/trace_parser.h" 45 #include "spdk/util.h" 46 } 47 48 static struct spdk_trace_parser *g_parser; 49 static const struct spdk_trace_flags *g_flags; 50 static struct spdk_json_write_ctx *g_json; 51 static bool g_print_tsc = false; 52 53 /* This is a bit ugly, but we don't want to include env_dpdk in the app, while spdk_util, which we 54 * do need, uses some of the functions implemented there. We're not actually using the functions 55 * that depend on those, so just define them as no-ops to allow the app to link. 56 */ 57 extern "C" { 58 void * 59 spdk_realloc(void *buf, size_t size, size_t align) 60 { 61 assert(false); 62 63 return NULL; 64 } 65 66 void 67 spdk_free(void *buf) 68 { 69 assert(false); 70 } 71 72 uint64_t 73 spdk_get_ticks(void) 74 { 75 return 0; 76 } 77 } /* extern "C" */ 78 79 static void usage(void); 80 81 static char *g_exe_name; 82 83 static float 84 get_us_from_tsc(uint64_t tsc, uint64_t tsc_rate) 85 { 86 return ((float)tsc) * 1000 * 1000 / tsc_rate; 87 } 88 89 static const char * 90 format_argname(const char *name) 91 { 92 static char namebuf[16]; 93 94 snprintf(namebuf, sizeof(namebuf), "%s: ", name); 95 return namebuf; 96 } 97 98 static void 99 print_ptr(const char *arg_string, uint64_t arg) 100 { 101 printf("%-7.7s0x%-14jx ", format_argname(arg_string), arg); 102 } 103 104 static void 105 print_uint64(const char *arg_string, uint64_t arg) 106 { 107 /* 108 * Print arg as signed, since -1 is a common value especially 109 * for FLUSH WRITEBUF when writev() returns -1 due to full 110 * socket buffer. 111 */ 112 printf("%-7.7s%-16jd ", format_argname(arg_string), arg); 113 } 114 115 static void 116 print_string(const char *arg_string, const char *arg) 117 { 118 printf("%-7.7s%-16.16s ", format_argname(arg_string), arg); 119 } 120 121 static void 122 print_size(uint32_t size) 123 { 124 if (size > 0) { 125 printf("size: %6u ", size); 126 } else { 127 printf("%13s", " "); 128 } 129 } 130 131 static void 132 print_object_id(const struct spdk_trace_tpoint *d, struct spdk_trace_parser_entry *entry) 133 { 134 /* Set size to 128 and 256 bytes to make sure we can fit all the characters we need */ 135 char related_id[128] = {'\0'}; 136 char ids[256] = {'\0'}; 137 138 if (entry->related_type != OBJECT_NONE) { 139 snprintf(related_id, sizeof(related_id), " (%c%jd)", 140 g_flags->object[entry->related_type].id_prefix, 141 entry->related_index); 142 } 143 144 snprintf(ids, sizeof(ids), "%c%jd%s", g_flags->object[d->object_type].id_prefix, 145 entry->object_index, related_id); 146 printf("id: %-17s", ids); 147 } 148 149 static void 150 print_float(const char *arg_string, float arg) 151 { 152 printf("%-7s%-16.3f ", format_argname(arg_string), arg); 153 } 154 155 static void 156 print_event(struct spdk_trace_parser_entry *entry, uint64_t tsc_rate, uint64_t tsc_offset) 157 { 158 struct spdk_trace_entry *e = entry->entry; 159 const struct spdk_trace_tpoint *d; 160 float us; 161 size_t i; 162 163 d = &g_flags->tpoint[e->tpoint_id]; 164 us = get_us_from_tsc(e->tsc - tsc_offset, tsc_rate); 165 166 printf("%2d: %10.3f ", entry->lcore, us); 167 if (g_print_tsc) { 168 printf("(%9ju) ", e->tsc - tsc_offset); 169 } 170 if (g_flags->owner[d->owner_type].id_prefix) { 171 printf("%c%02d ", g_flags->owner[d->owner_type].id_prefix, e->poller_id); 172 } else { 173 printf("%4s", " "); 174 } 175 176 printf("%-*s ", (int)sizeof(d->name), d->name); 177 print_size(e->size); 178 179 if (d->new_object) { 180 print_object_id(d, entry); 181 } else if (d->object_type != OBJECT_NONE) { 182 if (entry->object_index != UINT64_MAX) { 183 us = get_us_from_tsc(e->tsc - entry->object_start, tsc_rate); 184 print_object_id(d, entry); 185 print_float("time", us); 186 } else { 187 printf("id: N/A"); 188 } 189 } else if (e->object_id != 0) { 190 print_ptr("object", e->object_id); 191 } 192 193 for (i = 0; i < d->num_args; ++i) { 194 switch (d->args[i].type) { 195 case SPDK_TRACE_ARG_TYPE_PTR: 196 print_ptr(d->args[i].name, (uint64_t)entry->args[i].pointer); 197 break; 198 case SPDK_TRACE_ARG_TYPE_INT: 199 print_uint64(d->args[i].name, entry->args[i].integer); 200 break; 201 case SPDK_TRACE_ARG_TYPE_STR: 202 print_string(d->args[i].name, entry->args[i].string); 203 break; 204 } 205 } 206 printf("\n"); 207 } 208 209 static void 210 print_event_json(struct spdk_trace_parser_entry *entry, uint64_t tsc_rate, uint64_t tsc_offset) 211 { 212 struct spdk_trace_entry *e = entry->entry; 213 const struct spdk_trace_tpoint *d; 214 size_t i; 215 216 d = &g_flags->tpoint[e->tpoint_id]; 217 218 spdk_json_write_object_begin(g_json); 219 spdk_json_write_named_uint64(g_json, "lcore", entry->lcore); 220 spdk_json_write_named_uint64(g_json, "tpoint", e->tpoint_id); 221 spdk_json_write_named_uint64(g_json, "tsc", e->tsc); 222 223 if (g_flags->owner[d->owner_type].id_prefix) { 224 spdk_json_write_named_string_fmt(g_json, "poller", "%c%02d", 225 g_flags->owner[d->owner_type].id_prefix, 226 e->poller_id); 227 } 228 if (e->size != 0) { 229 spdk_json_write_named_uint32(g_json, "size", e->size); 230 } 231 if (d->new_object || d->object_type != OBJECT_NONE || e->object_id != 0) { 232 char object_type; 233 234 spdk_json_write_named_object_begin(g_json, "object"); 235 if (d->new_object) { 236 object_type = g_flags->object[d->object_type].id_prefix; 237 spdk_json_write_named_string_fmt(g_json, "id", "%c%" PRIu64, object_type, 238 entry->object_index); 239 } else if (d->object_type != OBJECT_NONE) { 240 object_type = g_flags->object[d->object_type].id_prefix; 241 if (entry->object_index != UINT64_MAX) { 242 spdk_json_write_named_string_fmt(g_json, "id", "%c%" PRIu64, 243 object_type, 244 entry->object_index); 245 spdk_json_write_named_uint64(g_json, "time", 246 e->tsc - entry->object_start); 247 } 248 } 249 spdk_json_write_named_uint64(g_json, "value", e->object_id); 250 spdk_json_write_object_end(g_json); 251 } 252 253 /* Print related objects array */ 254 if (entry->related_index != UINT64_MAX) { 255 spdk_json_write_named_string_fmt(g_json, "related", "%c%" PRIu64, 256 g_flags->object[entry->related_type].id_prefix, 257 entry->related_index); 258 } 259 260 if (d->num_args > 0) { 261 spdk_json_write_named_array_begin(g_json, "args"); 262 for (i = 0; i < d->num_args; ++i) { 263 switch (d->args[i].type) { 264 case SPDK_TRACE_ARG_TYPE_PTR: 265 spdk_json_write_uint64(g_json, (uint64_t)entry->args[i].pointer); 266 break; 267 case SPDK_TRACE_ARG_TYPE_INT: 268 spdk_json_write_uint64(g_json, entry->args[i].integer); 269 break; 270 case SPDK_TRACE_ARG_TYPE_STR: 271 spdk_json_write_string(g_json, entry->args[i].string); 272 break; 273 } 274 } 275 spdk_json_write_array_end(g_json); 276 } 277 278 spdk_json_write_object_end(g_json); 279 } 280 281 static void 282 process_event(struct spdk_trace_parser_entry *e, uint64_t tsc_rate, uint64_t tsc_offset) 283 { 284 if (g_json == NULL) { 285 print_event(e, tsc_rate, tsc_offset); 286 } else { 287 print_event_json(e, tsc_rate, tsc_offset); 288 } 289 } 290 291 static void 292 print_tpoint_definitions(void) 293 { 294 const struct spdk_trace_tpoint *tpoint; 295 size_t i, j; 296 297 /* We only care about these when printing JSON */ 298 if (!g_json) { 299 return; 300 } 301 302 spdk_json_write_named_uint64(g_json, "tsc_rate", g_flags->tsc_rate); 303 spdk_json_write_named_array_begin(g_json, "tpoints"); 304 305 for (i = 0; i < SPDK_COUNTOF(g_flags->tpoint); ++i) { 306 tpoint = &g_flags->tpoint[i]; 307 if (tpoint->tpoint_id == 0) { 308 continue; 309 } 310 311 spdk_json_write_object_begin(g_json); 312 spdk_json_write_named_string(g_json, "name", tpoint->name); 313 spdk_json_write_named_uint32(g_json, "id", tpoint->tpoint_id); 314 spdk_json_write_named_bool(g_json, "new_object", tpoint->new_object); 315 316 spdk_json_write_named_array_begin(g_json, "args"); 317 for (j = 0; j < tpoint->num_args; ++j) { 318 spdk_json_write_object_begin(g_json); 319 spdk_json_write_named_string(g_json, "name", tpoint->args[j].name); 320 spdk_json_write_named_uint32(g_json, "type", tpoint->args[j].type); 321 spdk_json_write_named_uint32(g_json, "size", tpoint->args[j].size); 322 spdk_json_write_object_end(g_json); 323 } 324 spdk_json_write_array_end(g_json); 325 spdk_json_write_object_end(g_json); 326 } 327 328 spdk_json_write_array_end(g_json); 329 } 330 331 static int 332 print_json(void *cb_ctx, const void *data, size_t size) 333 { 334 ssize_t rc; 335 336 while (size > 0) { 337 rc = write(STDOUT_FILENO, data, size); 338 if (rc < 0) { 339 fprintf(stderr, "%s: %s\n", g_exe_name, spdk_strerror(errno)); 340 abort(); 341 } 342 343 size -= rc; 344 } 345 346 return 0; 347 } 348 349 static void usage(void) 350 { 351 fprintf(stderr, "usage:\n"); 352 fprintf(stderr, " %s <option> <lcore#>\n", g_exe_name); 353 fprintf(stderr, " '-c' to display single lcore history\n"); 354 fprintf(stderr, " '-t' to display TSC offset for each event\n"); 355 fprintf(stderr, " '-s' to specify spdk_trace shm name for a\n"); 356 fprintf(stderr, " currently running process\n"); 357 fprintf(stderr, " '-i' to specify the shared memory ID\n"); 358 fprintf(stderr, " '-p' to specify the trace PID\n"); 359 fprintf(stderr, " (If -s is specified, then one of\n"); 360 fprintf(stderr, " -i or -p must be specified)\n"); 361 fprintf(stderr, " '-f' to specify a tracepoint file name\n"); 362 fprintf(stderr, " (-s and -f are mutually exclusive)\n"); 363 fprintf(stderr, " '-j' to use JSON to format the output\n"); 364 } 365 366 int main(int argc, char **argv) 367 { 368 struct spdk_trace_parser_opts opts; 369 struct spdk_trace_parser_entry entry; 370 int lcore = SPDK_TRACE_MAX_LCORE; 371 uint64_t tsc_offset, entry_count; 372 const char *app_name = NULL; 373 const char *file_name = NULL; 374 int op, i; 375 char shm_name[64]; 376 int shm_id = -1, shm_pid = -1; 377 bool json = false; 378 379 g_exe_name = argv[0]; 380 while ((op = getopt(argc, argv, "c:f:i:jp:s:t")) != -1) { 381 switch (op) { 382 case 'c': 383 lcore = atoi(optarg); 384 if (lcore > SPDK_TRACE_MAX_LCORE) { 385 fprintf(stderr, "Selected lcore: %d " 386 "exceeds maximum %d\n", lcore, 387 SPDK_TRACE_MAX_LCORE); 388 exit(1); 389 } 390 break; 391 case 'i': 392 shm_id = atoi(optarg); 393 break; 394 case 'p': 395 shm_pid = atoi(optarg); 396 break; 397 case 's': 398 app_name = optarg; 399 break; 400 case 'f': 401 file_name = optarg; 402 break; 403 case 't': 404 g_print_tsc = true; 405 break; 406 case 'j': 407 json = true; 408 break; 409 default: 410 usage(); 411 exit(1); 412 } 413 } 414 415 if (file_name != NULL && app_name != NULL) { 416 fprintf(stderr, "-f and -s are mutually exclusive\n"); 417 usage(); 418 exit(1); 419 } 420 421 if (file_name == NULL && app_name == NULL) { 422 fprintf(stderr, "One of -f and -s must be specified\n"); 423 usage(); 424 exit(1); 425 } 426 427 if (json) { 428 g_json = spdk_json_write_begin(print_json, NULL, 0); 429 if (g_json == NULL) { 430 fprintf(stderr, "Failed to allocate JSON write context\n"); 431 exit(1); 432 } 433 } 434 435 if (!file_name) { 436 if (shm_id >= 0) { 437 snprintf(shm_name, sizeof(shm_name), "/%s_trace.%d", app_name, shm_id); 438 } else { 439 snprintf(shm_name, sizeof(shm_name), "/%s_trace.pid%d", app_name, shm_pid); 440 } 441 file_name = shm_name; 442 } 443 444 opts.filename = file_name; 445 opts.lcore = lcore; 446 opts.mode = app_name == NULL ? SPDK_TRACE_PARSER_MODE_FILE : SPDK_TRACE_PARSER_MODE_SHM; 447 g_parser = spdk_trace_parser_init(&opts); 448 if (g_parser == NULL) { 449 fprintf(stderr, "Failed to initialize trace parser\n"); 450 exit(1); 451 } 452 453 g_flags = spdk_trace_parser_get_flags(g_parser); 454 if (!g_json) { 455 printf("TSC Rate: %ju\n", g_flags->tsc_rate); 456 } else { 457 spdk_json_write_object_begin(g_json); 458 print_tpoint_definitions(); 459 spdk_json_write_named_array_begin(g_json, "entries"); 460 } 461 462 for (i = 0; i < SPDK_TRACE_MAX_LCORE; ++i) { 463 if (lcore == SPDK_TRACE_MAX_LCORE || i == lcore) { 464 entry_count = spdk_trace_parser_get_entry_count(g_parser, i); 465 if (entry_count > 0) { 466 printf("Trace Size of lcore (%d): %ju\n", i, entry_count); 467 } 468 } 469 } 470 471 tsc_offset = spdk_trace_parser_get_tsc_offset(g_parser); 472 while (spdk_trace_parser_next_entry(g_parser, &entry)) { 473 if (entry.entry->tsc < tsc_offset) { 474 continue; 475 } 476 process_event(&entry, g_flags->tsc_rate, tsc_offset); 477 } 478 479 if (g_json != NULL) { 480 spdk_json_write_array_end(g_json); 481 spdk_json_write_object_end(g_json); 482 spdk_json_write_end(g_json); 483 } 484 485 spdk_trace_parser_cleanup(g_parser); 486 487 return (0); 488 } 489