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