Line data    Source code

       1             : /*   SPDX-License-Identifier: BSD-3-Clause
       2             :  *   Copyright (C) 2021 Intel Corporation.
       3             :  *   All rights reserved.
       4             :  */
       5             : 
       6             : #include "spdk/stdinc.h"
       7             : #include "spdk/likely.h"
       8             : #include "spdk/log.h"
       9             : #include "spdk/trace_parser.h"
      10             : #include "spdk/util.h"
      11             : #include "spdk/env.h"
      12             : 
      13             : #include <exception>
      14             : #include <map>
      15             : #include <new>
      16             : 
      17             : struct entry_key {
      18           0 :         entry_key(uint16_t _lcore, uint64_t _tsc) : lcore(_lcore), tsc(_tsc) {}
      19             :         uint16_t lcore;
      20             :         uint64_t tsc;
      21             : };
      22             : 
      23             : class compare_entry_key
      24             : {
      25             : public:
      26           0 :         bool operator()(const entry_key &first, const entry_key &second) const
      27             :         {
      28           0 :                 if (first.tsc == second.tsc) {
      29           0 :                         return first.lcore < second.lcore;
      30             :                 } else {
      31           0 :                         return first.tsc < second.tsc;
      32             :                 }
      33             :         }
      34             : };
      35             : 
      36             : typedef std::map<entry_key, spdk_trace_entry *, compare_entry_key> entry_map;
      37             : 
      38             : struct argument_context {
      39             :         spdk_trace_entry        *entry;
      40             :         spdk_trace_entry_buffer *buffer;
      41             :         uint16_t                lcore;
      42             :         size_t                  offset;
      43             : 
      44           0 :         argument_context(spdk_trace_entry *entry, uint16_t lcore) :
      45           0 :                 entry(entry), lcore(lcore)
      46             :         {
      47           0 :                 buffer = reinterpret_cast<spdk_trace_entry_buffer *>(entry);
      48             : 
      49             :                 /* The first argument resides within the spdk_trace_entry structure, so the initial
      50             :                  * offset needs to be adjusted to the start of the spdk_trace_entry.args array
      51             :                  */
      52           0 :                 offset = offsetof(spdk_trace_entry, args) -
      53             :                          offsetof(spdk_trace_entry_buffer, data);
      54           0 :         }
      55             : };
      56             : 
      57             : struct object_stats {
      58             :         std::map<uint64_t, uint64_t>      index;
      59             :         std::map<uint64_t, uint64_t>      start;
      60             :         uint64_t                        counter;
      61             : 
      62           0 :         object_stats() : counter(0) {}
      63             : };
      64             : 
      65             : struct spdk_trace_parser {
      66             :         spdk_trace_parser(const spdk_trace_parser_opts *opts);
      67             :         ~spdk_trace_parser();
      68             :         spdk_trace_parser(const spdk_trace_parser &) = delete;
      69             :         spdk_trace_parser &operator=(const spdk_trace_parser &) = delete;
      70           0 :         const spdk_trace_file *file() const { return _trace_file; }
      71           0 :         uint64_t tsc_offset() const { return _tsc_offset; }
      72             :         bool next_entry(spdk_trace_parser_entry *entry);
      73             :         uint64_t entry_count(uint16_t lcore) const;
      74             : private:
      75             :         spdk_trace_entry_buffer *get_next_buffer(spdk_trace_entry_buffer *buf, uint16_t lcore);
      76             :         bool build_arg(argument_context *argctx, const spdk_trace_argument *arg, int argid,
      77             :                        spdk_trace_parser_entry *pe);
      78             :         void populate_events(spdk_trace_history *history, int num_entries, bool overflowed);
      79             :         bool init(const spdk_trace_parser_opts *opts);
      80             :         void cleanup();
      81             : 
      82             :         spdk_trace_file         *_trace_file;
      83             :         size_t                  _map_size;
      84             :         int                     _fd;
      85             :         uint64_t                _tsc_offset;
      86             :         entry_map               _entries;
      87             :         entry_map::iterator     _iter;
      88             :         object_stats            _stats[SPDK_TRACE_MAX_OBJECT];
      89             : };
      90             : 
      91             : uint64_t
      92           0 : spdk_trace_parser::entry_count(uint16_t lcore) const
      93             : {
      94             :         spdk_trace_history *history;
      95             : 
      96           0 :         if (lcore >= SPDK_TRACE_MAX_LCORE) {
      97           0 :                 return 0;
      98             :         }
      99             : 
     100           0 :         history = spdk_get_per_lcore_history(_trace_file, lcore);
     101             : 
     102           0 :         return history == NULL ? 0 : history->num_entries;
     103             : }
     104             : 
     105             : spdk_trace_entry_buffer *
     106           0 : spdk_trace_parser::get_next_buffer(spdk_trace_entry_buffer *buf, uint16_t lcore)
     107             : {
     108             :         spdk_trace_history *history;
     109             : 
     110           0 :         history = spdk_get_per_lcore_history(_trace_file, lcore);
     111           0 :         assert(history);
     112             : 
     113           0 :         if (spdk_unlikely(static_cast<void *>(buf) ==
     114             :                           static_cast<void *>(&history->entries[history->num_entries - 1]))) {
     115           0 :                 return reinterpret_cast<spdk_trace_entry_buffer *>(&history->entries[0]);
     116             :         } else {
     117           0 :                 return buf + 1;
     118             :         }
     119             : }
     120             : 
     121             : bool
     122           0 : spdk_trace_parser::build_arg(argument_context *argctx, const spdk_trace_argument *arg, int argid,
     123             :                              spdk_trace_parser_entry *pe)
     124             : {
     125           0 :         spdk_trace_entry *entry = argctx->entry;
     126           0 :         spdk_trace_entry_buffer *buffer = argctx->buffer;
     127             :         size_t curlen, argoff;
     128             : 
     129           0 :         argoff = 0;
     130           0 :         pe->args[argid].is_related = false;
     131             :         /* Make sure that if we only copy a 4-byte integer, that the upper bytes have already been
     132             :          * zeroed.
     133             :          */
     134           0 :         pe->args[argid].u.integer = 0;
     135           0 :         while (argoff < arg->size) {
     136           0 :                 if (argctx->offset == sizeof(buffer->data)) {
     137           0 :                         buffer = get_next_buffer(buffer, argctx->lcore);
     138           0 :                         if (spdk_unlikely(buffer->tpoint_id != SPDK_TRACE_MAX_TPOINT_ID ||
     139             :                                           buffer->tsc != entry->tsc)) {
     140           0 :                                 return false;
     141             :                         }
     142             : 
     143           0 :                         argctx->offset = 0;
     144           0 :                         argctx->buffer = buffer;
     145             :                 }
     146             : 
     147           0 :                 curlen = spdk_min(sizeof(buffer->data) - argctx->offset, arg->size - argoff);
     148           0 :                 if (argoff < sizeof(pe->args[0].u.string)) {
     149           0 :                         memcpy(&pe->args[argid].u.string[argoff], &buffer->data[argctx->offset],
     150           0 :                                spdk_min(curlen, sizeof(pe->args[0].u.string) - argoff));
     151             :                 }
     152             : 
     153           0 :                 argctx->offset += curlen;
     154           0 :                 argoff += curlen;
     155             :         }
     156             : 
     157           0 :         return true;
     158             : }
     159             : 
     160             : bool
     161           0 : spdk_trace_parser::next_entry(spdk_trace_parser_entry *pe)
     162             : {
     163             :         spdk_trace_tpoint *tpoint;
     164             :         spdk_trace_entry *entry;
     165             :         object_stats *stats;
     166           0 :         std::map<uint64_t, uint64_t>::iterator related_kv;
     167             : 
     168           0 :         if (_iter == _entries.end()) {
     169           0 :                 return false;
     170             :         }
     171             : 
     172           0 :         pe->entry = entry = _iter->second;
     173           0 :         pe->lcore = _iter->first.lcore;
     174             :         /* Set related index to the max value to indicate "empty" state */
     175           0 :         pe->related_index = UINT64_MAX;
     176           0 :         pe->related_type = OBJECT_NONE;
     177           0 :         tpoint = &_trace_file->tpoint[entry->tpoint_id];
     178           0 :         stats = &_stats[tpoint->object_type];
     179             : 
     180           0 :         if (tpoint->new_object) {
     181           0 :                 stats->index[entry->object_id] = stats->counter++;
     182           0 :                 stats->start[entry->object_id] = entry->tsc;
     183             :         }
     184             : 
     185           0 :         if (tpoint->object_type != OBJECT_NONE) {
     186           0 :                 if (spdk_likely(stats->start.find(entry->object_id) != stats->start.end())) {
     187           0 :                         pe->object_index = stats->index[entry->object_id];
     188           0 :                         pe->object_start = stats->start[entry->object_id];
     189             :                 } else {
     190           0 :                         pe->object_index = UINT64_MAX;
     191           0 :                         pe->object_start = UINT64_MAX;
     192             :                 }
     193             :         }
     194             : 
     195           0 :         argument_context argctx(entry, pe->lcore);
     196           0 :         for (uint8_t i = 0; i < tpoint->num_args; ++i) {
     197           0 :                 if (!build_arg(&argctx, &tpoint->args[i], i, pe)) {
     198           0 :                         SPDK_ERRLOG("Failed to parse tracepoint argument\n");
     199           0 :                         return false;
     200             :                 }
     201             :         }
     202             : 
     203           0 :         for (uint8_t i = 0; i < SPDK_TRACE_MAX_RELATIONS; ++i) {
     204             :                 /* The relations are stored inside a tpoint, which means there might be
     205             :                  * multiple objects bound to a single tpoint. */
     206           0 :                 if (tpoint->related_objects[i].object_type == OBJECT_NONE) {
     207           0 :                         break;
     208             :                 }
     209           0 :                 stats = &_stats[tpoint->related_objects[i].object_type];
     210           0 :                 related_kv = stats->index.find(reinterpret_cast<uint64_t>
     211           0 :                                                (pe->args[tpoint->related_objects[i].arg_index].u.pointer));
     212             :                 /* To avoid parsing the whole array, object index and type are stored
     213             :                  * directly inside spdk_trace_parser_entry. */
     214           0 :                 if (related_kv != stats->index.end()) {
     215           0 :                         pe->related_index = related_kv->second;
     216           0 :                         pe->related_type = tpoint->related_objects[i].object_type;
     217           0 :                         pe->args[tpoint->related_objects[i].arg_index].is_related = true;
     218           0 :                         break;
     219             :                 }
     220             :         }
     221             : 
     222           0 :         _iter++;
     223           0 :         return true;
     224             : }
     225             : 
     226             : void
     227           0 : spdk_trace_parser::populate_events(spdk_trace_history *history, int num_entries, bool overflowed)
     228             : {
     229             :         int i, num_entries_filled;
     230             :         spdk_trace_entry *e;
     231             :         int first, last, lcore;
     232             : 
     233           0 :         lcore = history->lcore;
     234           0 :         e = history->entries;
     235             : 
     236           0 :         num_entries_filled = num_entries;
     237           0 :         while (e[num_entries_filled - 1].tsc == 0) {
     238           0 :                 num_entries_filled--;
     239             :         }
     240             : 
     241           0 :         if (num_entries == num_entries_filled) {
     242           0 :                 first = last = 0;
     243           0 :                 for (i = 1; i < num_entries; i++) {
     244           0 :                         if (e[i].tsc < e[first].tsc) {
     245           0 :                                 first = i;
     246             :                         }
     247           0 :                         if (e[i].tsc > e[last].tsc) {
     248           0 :                                 last = i;
     249             :                         }
     250             :                 }
     251             :         } else {
     252           0 :                 first = 0;
     253           0 :                 last = num_entries_filled - 1;
     254             :         }
     255             : 
     256             :         /*
     257             :          * We keep track of the highest first TSC out of all reactors iff. any
     258             :          * have overflowed their circular buffer.
     259             :          *  We will ignore any events that occurred before this TSC on any
     260             :          *  other reactors.  This will ensure we only print data for the
     261             :          *  subset of time where we have data across all reactors.
     262             :          */
     263           0 :         if (e[first].tsc > _tsc_offset && overflowed) {
     264           0 :                 _tsc_offset = e[first].tsc;
     265             :         }
     266             : 
     267           0 :         i = first;
     268             :         while (1) {
     269           0 :                 if (e[i].tpoint_id != SPDK_TRACE_MAX_TPOINT_ID) {
     270           0 :                         _entries[entry_key(lcore, e[i].tsc)] = &e[i];
     271             :                 }
     272           0 :                 if (i == last) {
     273           0 :                         break;
     274             :                 }
     275           0 :                 i++;
     276           0 :                 if (i == num_entries_filled) {
     277           0 :                         i = 0;
     278             :                 }
     279             :         }
     280           0 : }
     281             : 
     282             : bool
     283           0 : spdk_trace_parser::init(const spdk_trace_parser_opts *opts)
     284             : {
     285             :         spdk_trace_history *history;
     286           0 :         struct stat st;
     287             :         int rc, i, entry_num;
     288             :         bool overflowed;
     289             : 
     290           0 :         switch (opts->mode) {
     291           0 :         case SPDK_TRACE_PARSER_MODE_FILE:
     292           0 :                 _fd = open(opts->filename, O_RDONLY);
     293           0 :                 break;
     294           0 :         case SPDK_TRACE_PARSER_MODE_SHM:
     295           0 :                 _fd = shm_open(opts->filename, O_RDONLY, 0600);
     296           0 :                 break;
     297           0 :         default:
     298           0 :                 SPDK_ERRLOG("Invalid mode: %d\n", opts->mode);
     299           0 :                 return false;
     300             :         }
     301             : 
     302           0 :         if (_fd < 0) {
     303           0 :                 SPDK_ERRLOG("Could not open trace file: %s (%d)\n", opts->filename, errno);
     304           0 :                 return false;
     305             :         }
     306             : 
     307           0 :         rc = fstat(_fd, &st);
     308           0 :         if (rc < 0) {
     309           0 :                 SPDK_ERRLOG("Could not get size of trace file: %s\n", opts->filename);
     310           0 :                 return false;
     311             :         }
     312             : 
     313           0 :         if ((size_t)st.st_size < sizeof(*_trace_file)) {
     314           0 :                 SPDK_ERRLOG("Invalid trace file: %s\n", opts->filename);
     315           0 :                 return false;
     316             :         }
     317             : 
     318             :         /* Map the header of trace file */
     319           0 :         _map_size = sizeof(*_trace_file);
     320           0 :         _trace_file = static_cast<spdk_trace_file *>(mmap(NULL, _map_size, PROT_READ,
     321             :                         MAP_SHARED, _fd, 0));
     322           0 :         if (_trace_file == MAP_FAILED) {
     323           0 :                 SPDK_ERRLOG("Could not mmap trace file: %s\n", opts->filename);
     324           0 :                 _trace_file = NULL;
     325           0 :                 return false;
     326             :         }
     327             : 
     328             :         /* Remap the entire trace file */
     329           0 :         _map_size = spdk_get_trace_file_size(_trace_file);
     330           0 :         munmap(_trace_file, sizeof(*_trace_file));
     331           0 :         if ((size_t)st.st_size < _map_size) {
     332           0 :                 SPDK_ERRLOG("Trace file %s is not valid\n", opts->filename);
     333           0 :                 _trace_file = NULL;
     334           0 :                 return false;
     335             :         }
     336           0 :         _trace_file = static_cast<spdk_trace_file *>(mmap(NULL, _map_size, PROT_READ,
     337             :                         MAP_SHARED, _fd, 0));
     338           0 :         if (_trace_file == MAP_FAILED) {
     339           0 :                 SPDK_ERRLOG("Could not mmap trace file: %s\n", opts->filename);
     340           0 :                 _trace_file = NULL;
     341           0 :                 return false;
     342             :         }
     343             : 
     344           0 :         if (opts->lcore == SPDK_TRACE_MAX_LCORE) {
     345             :                 /* Check if any reactors have overwritten their circular buffer. */
     346           0 :                 for (i = 0; i < SPDK_TRACE_MAX_LCORE; i++) {
     347           0 :                         history = spdk_get_per_lcore_history(_trace_file, i);
     348           0 :                         if (history == NULL || history->num_entries == 0 || history->entries[0].tsc == 0) {
     349           0 :                                 continue;
     350             :                         }
     351           0 :                         entry_num = history->num_entries - 1;
     352           0 :                         overflowed = true;
     353           0 :                         while (entry_num >= 0) {
     354           0 :                                 if (history->entries[entry_num].tsc == 0) {
     355           0 :                                         overflowed = false;
     356           0 :                                         break;
     357             :                                 }
     358           0 :                                 entry_num--;
     359             :                         }
     360           0 :                         if (overflowed) {
     361           0 :                                 break;
     362             :                         }
     363             : 
     364             :                 }
     365           0 :                 for (i = 0; i < SPDK_TRACE_MAX_LCORE; i++) {
     366           0 :                         history = spdk_get_per_lcore_history(_trace_file, i);
     367           0 :                         if (history == NULL || history->num_entries == 0 || history->entries[0].tsc == 0) {
     368           0 :                                 continue;
     369             :                         }
     370           0 :                         populate_events(history, history->num_entries, overflowed);
     371             :                 }
     372             :         } else {
     373           0 :                 history = spdk_get_per_lcore_history(_trace_file, opts->lcore);
     374           0 :                 if (history == NULL) {
     375           0 :                         SPDK_ERRLOG("Trace file %s has no trace history for lcore %d\n",
     376             :                                     opts->filename, opts->lcore);
     377           0 :                         return false;
     378             :                 }
     379           0 :                 if (history->num_entries > 0 && history->entries[0].tsc != 0) {
     380           0 :                         populate_events(history, history->num_entries, false);
     381             :                 }
     382             :         }
     383             : 
     384           0 :         _iter = _entries.begin();
     385           0 :         return true;
     386             : }
     387             : 
     388             : void
     389           0 : spdk_trace_parser::cleanup()
     390             : {
     391           0 :         if (_trace_file != NULL) {
     392           0 :                 munmap(_trace_file, _map_size);
     393             :         }
     394             : 
     395           0 :         if (_fd > 0) {
     396           0 :                 close(_fd);
     397             :         }
     398           0 : }
     399             : 
     400           0 : spdk_trace_parser::spdk_trace_parser(const spdk_trace_parser_opts *opts) :
     401           0 :         _trace_file(NULL),
     402           0 :         _map_size(0),
     403           0 :         _fd(-1),
     404           0 :         _tsc_offset(0)
     405             : {
     406           0 :         if (!init(opts)) {
     407           0 :                 cleanup();
     408           0 :                 throw std::exception();
     409             :         }
     410           0 : }
     411             : 
     412           0 : spdk_trace_parser::~spdk_trace_parser()
     413             : {
     414           0 :         cleanup();
     415           0 : }
     416             : 
     417             : struct spdk_trace_parser *
     418           0 : spdk_trace_parser_init(const struct spdk_trace_parser_opts *opts)
     419             : {
     420             :         try {
     421           0 :                 return new spdk_trace_parser(opts);
     422           0 :         } catch (...) {
     423           0 :                 return NULL;
     424           0 :         }
     425             : }
     426             : 
     427             : void
     428           0 : spdk_trace_parser_cleanup(struct spdk_trace_parser *parser)
     429             : {
     430           0 :         delete parser;
     431           0 : }
     432             : 
     433             : const struct spdk_trace_file *
     434           0 : spdk_trace_parser_get_file(const struct spdk_trace_parser *parser)
     435             : {
     436           0 :         return parser->file();
     437             : }
     438             : 
     439             : uint64_t
     440           0 : spdk_trace_parser_get_tsc_offset(const struct spdk_trace_parser *parser)
     441             : {
     442           0 :         return parser->tsc_offset();
     443             : }
     444             : 
     445             : bool
     446           0 : spdk_trace_parser_next_entry(struct spdk_trace_parser *parser,
     447             :                              struct spdk_trace_parser_entry *entry)
     448             : {
     449           0 :         return parser->next_entry(entry);
     450             : }
     451             : 
     452             : uint64_t
     453           0 : spdk_trace_parser_get_entry_count(const struct spdk_trace_parser *parser, uint16_t lcore)
     454             : {
     455           0 :         return parser->entry_count(lcore);
     456             : }