Line data Source code
1 : /* SPDX-License-Identifier: BSD-3-Clause
2 : * Copyright (C) 2016 Intel Corporation.
3 : * All rights reserved.
4 : */
5 :
6 : #include "spdk/stdinc.h"
7 :
8 : #include "spdk/env.h"
9 : #include "spdk/string.h"
10 : #include "spdk/trace.h"
11 : #include "spdk/util.h"
12 : #include "spdk/barrier.h"
13 : #include "spdk/log.h"
14 : #include "spdk/cpuset.h"
15 : #include "spdk/likely.h"
16 : #include "spdk/bit_array.h"
17 : #include "trace_internal.h"
18 :
19 : static int g_trace_fd = -1;
20 : static char g_shm_name[64];
21 :
22 : static __thread uint32_t t_ut_array_index;
23 : static __thread struct spdk_trace_history *t_ut_lcore_history;
24 :
25 : static uint32_t g_user_thread_index_start;
26 : struct spdk_trace_file *g_trace_file;
27 : static struct spdk_bit_array *g_ut_array;
28 : static pthread_mutex_t g_ut_array_mutex;
29 :
30 : #define TRACE_NUM_OWNERS (16 * 1024)
31 : #define TRACE_OWNER_DESCRIPTION_SIZE (119)
32 : SPDK_STATIC_ASSERT(sizeof(struct spdk_trace_owner) == 9, "incorrect size");
33 : SPDK_STATIC_ASSERT(sizeof(struct spdk_trace_owner) + TRACE_OWNER_DESCRIPTION_SIZE == 128,
34 : "incorrect size");
35 :
36 : static inline struct spdk_trace_entry *
37 0 : get_trace_entry(struct spdk_trace_history *history, uint64_t offset)
38 : {
39 0 : return &history->entries[offset & (history->num_entries - 1)];
40 : }
41 :
42 : void
43 0 : _spdk_trace_record(uint64_t tsc, uint16_t tpoint_id, uint16_t owner_id, uint32_t size,
44 : uint64_t object_id, int num_args, ...)
45 : {
46 0 : struct spdk_trace_history *lcore_history;
47 0 : struct spdk_trace_entry *next_entry;
48 0 : struct spdk_trace_entry_buffer *buffer;
49 0 : struct spdk_trace_tpoint *tpoint;
50 0 : struct spdk_trace_argument *argument;
51 0 : unsigned lcore, i, offset, num_entries, arglen, argoff, curlen;
52 0 : uint64_t intval;
53 0 : void *argval;
54 0 : va_list vl;
55 :
56 0 : lcore = spdk_env_get_current_core();
57 0 : if (spdk_likely(lcore != SPDK_ENV_LCORE_ID_ANY)) {
58 0 : lcore_history = spdk_get_per_lcore_history(g_trace_file, lcore);
59 0 : } else if (t_ut_lcore_history != NULL) {
60 0 : lcore_history = t_ut_lcore_history;
61 0 : } else {
62 0 : return;
63 : }
64 :
65 0 : if (tsc == 0) {
66 0 : tsc = spdk_get_ticks();
67 0 : }
68 :
69 0 : lcore_history->tpoint_count[tpoint_id]++;
70 :
71 0 : tpoint = &g_trace_file->tpoint[tpoint_id];
72 : /* Make sure that the number of arguments passed matches tracepoint definition */
73 0 : if (spdk_unlikely(tpoint->num_args != num_args)) {
74 0 : assert(0 && "Unexpected number of tracepoint arguments");
75 : return;
76 : }
77 :
78 : /* Get next entry index in the circular buffer */
79 0 : next_entry = get_trace_entry(lcore_history, lcore_history->next_entry);
80 0 : next_entry->tsc = tsc;
81 0 : next_entry->tpoint_id = tpoint_id;
82 0 : next_entry->owner_id = owner_id;
83 0 : next_entry->size = size;
84 0 : next_entry->object_id = object_id;
85 :
86 0 : num_entries = 1;
87 0 : buffer = (struct spdk_trace_entry_buffer *)next_entry;
88 : /* The initial offset needs to be adjusted by the fields present in the first entry
89 : * (owner_id, size, etc.).
90 : */
91 0 : offset = offsetof(struct spdk_trace_entry, args) -
92 : offsetof(struct spdk_trace_entry_buffer, data);
93 :
94 0 : va_start(vl, num_args);
95 0 : for (i = 0; i < tpoint->num_args; ++i) {
96 0 : argument = &tpoint->args[i];
97 0 : switch (argument->type) {
98 : case SPDK_TRACE_ARG_TYPE_STR:
99 0 : argval = va_arg(vl, void *);
100 0 : arglen = strnlen((const char *)argval, argument->size - 1) + 1;
101 0 : break;
102 : case SPDK_TRACE_ARG_TYPE_INT:
103 : case SPDK_TRACE_ARG_TYPE_PTR:
104 0 : if (argument->size == 8) {
105 0 : intval = va_arg(vl, uint64_t);
106 0 : } else {
107 0 : intval = va_arg(vl, uint32_t);
108 : }
109 0 : argval = &intval;
110 0 : arglen = argument->size;
111 0 : break;
112 : default:
113 0 : assert(0 && "Invalid trace argument type");
114 : return;
115 : }
116 :
117 : /* Copy argument's data. For some argument types (strings) user is allowed to pass a
118 : * value that is either larger or smaller than what's defined in the tracepoint's
119 : * description. If the value is larger, we'll truncate it, while if it's smaller,
120 : * we'll only fill portion of the buffer, without touching the rest. For instance,
121 : * if the definition marks an argument as 40B and user passes 12B string, we'll only
122 : * copy 13B (accounting for the NULL terminator).
123 : */
124 0 : argoff = 0;
125 0 : while (argoff < argument->size) {
126 : /* Current buffer is full, we need to acquire another one */
127 0 : if (spdk_unlikely(offset == sizeof(buffer->data))) {
128 0 : buffer = (struct spdk_trace_entry_buffer *) get_trace_entry(
129 0 : lcore_history,
130 0 : lcore_history->next_entry + num_entries);
131 0 : buffer->tpoint_id = SPDK_TRACE_MAX_TPOINT_ID;
132 0 : buffer->tsc = tsc;
133 0 : num_entries++;
134 0 : offset = 0;
135 0 : }
136 :
137 0 : curlen = spdk_min(sizeof(buffer->data) - offset, argument->size - argoff);
138 0 : if (spdk_likely(argoff < arglen)) {
139 0 : assert(argval != NULL);
140 0 : memcpy(&buffer->data[offset], (uint8_t *)argval + argoff,
141 0 : spdk_min(curlen, arglen - argoff));
142 0 : }
143 :
144 0 : offset += curlen;
145 0 : argoff += curlen;
146 : }
147 :
148 : /* Make sure that truncated strings are NULL-terminated */
149 0 : if (spdk_unlikely(argument->type == SPDK_TRACE_ARG_TYPE_STR)) {
150 0 : assert(offset > 0);
151 0 : buffer->data[offset - 1] = '\0';
152 0 : }
153 0 : }
154 0 : va_end(vl);
155 :
156 : /* Ensure all elements of the trace entry are visible to outside trace tools */
157 0 : spdk_smp_wmb();
158 0 : lcore_history->next_entry += num_entries;
159 0 : }
160 :
161 : int
162 0 : spdk_trace_register_user_thread(void)
163 : {
164 0 : int ret;
165 0 : uint32_t ut_index;
166 0 : pthread_t tid;
167 :
168 0 : if (!g_ut_array) {
169 0 : SPDK_ERRLOG("user thread array not created\n");
170 0 : return -ENOMEM;
171 : }
172 :
173 0 : if (spdk_env_get_current_core() != SPDK_ENV_LCORE_ID_ANY) {
174 0 : SPDK_ERRLOG("cannot register an user thread from a dedicated cpu %d\n",
175 : spdk_env_get_current_core());
176 0 : return -EINVAL;
177 : }
178 :
179 0 : pthread_mutex_lock(&g_ut_array_mutex);
180 :
181 0 : t_ut_array_index = spdk_bit_array_find_first_clear(g_ut_array, 0);
182 0 : if (t_ut_array_index == UINT32_MAX) {
183 0 : SPDK_ERRLOG("could not find an entry in the user thread array\n");
184 0 : pthread_mutex_unlock(&g_ut_array_mutex);
185 0 : return -ENOENT;
186 : }
187 :
188 0 : ut_index = t_ut_array_index + g_user_thread_index_start;
189 :
190 0 : t_ut_lcore_history = spdk_get_per_lcore_history(g_trace_file, ut_index);
191 :
192 0 : assert(t_ut_lcore_history != NULL);
193 :
194 0 : memset(g_trace_file->tname[ut_index], 0, SPDK_TRACE_THREAD_NAME_LEN);
195 :
196 0 : tid = pthread_self();
197 0 : ret = pthread_getname_np(tid, g_trace_file->tname[ut_index], SPDK_TRACE_THREAD_NAME_LEN);
198 0 : if (ret) {
199 0 : SPDK_ERRLOG("cannot get thread name\n");
200 0 : pthread_mutex_unlock(&g_ut_array_mutex);
201 0 : return ret;
202 : }
203 :
204 0 : spdk_bit_array_set(g_ut_array, t_ut_array_index);
205 :
206 0 : pthread_mutex_unlock(&g_ut_array_mutex);
207 :
208 0 : return 0;
209 0 : }
210 :
211 : int
212 0 : spdk_trace_unregister_user_thread(void)
213 : {
214 0 : if (!g_ut_array) {
215 0 : SPDK_ERRLOG("user thread array not created\n");
216 0 : return -ENOMEM;
217 : }
218 :
219 0 : if (spdk_env_get_current_core() != SPDK_ENV_LCORE_ID_ANY) {
220 0 : SPDK_ERRLOG("cannot unregister an user thread from a dedicated cpu %d\n",
221 : spdk_env_get_current_core());
222 0 : return -EINVAL;
223 : }
224 :
225 0 : pthread_mutex_lock(&g_ut_array_mutex);
226 :
227 0 : spdk_bit_array_clear(g_ut_array, t_ut_array_index);
228 :
229 0 : pthread_mutex_unlock(&g_ut_array_mutex);
230 :
231 0 : return 0;
232 0 : }
233 :
234 : int
235 0 : spdk_trace_init(const char *shm_name, uint64_t num_entries, uint32_t num_threads)
236 : {
237 0 : uint32_t i = 0, max_dedicated_cpu = 0;
238 0 : uint64_t file_size;
239 0 : uint64_t lcore_offsets[SPDK_TRACE_MAX_LCORE] = { 0 };
240 0 : uint64_t owner_offset;
241 0 : struct spdk_cpuset cpuset = {};
242 :
243 : /* 0 entries requested - skip trace initialization */
244 0 : if (num_entries == 0) {
245 0 : return 0;
246 : }
247 :
248 0 : if (num_threads >= SPDK_TRACE_MAX_LCORE) {
249 0 : SPDK_ERRLOG("cannot alloc trace entries for %d user threads\n", num_threads);
250 0 : SPDK_ERRLOG("supported maximum %d threads\n", SPDK_TRACE_MAX_LCORE - 1);
251 0 : return 1;
252 : }
253 :
254 0 : spdk_cpuset_zero(&cpuset);
255 0 : file_size = sizeof(struct spdk_trace_file);
256 0 : SPDK_ENV_FOREACH_CORE(i) {
257 0 : spdk_cpuset_set_cpu(&cpuset, i, true);
258 0 : lcore_offsets[i] = file_size;
259 0 : file_size += spdk_get_trace_history_size(num_entries);
260 0 : max_dedicated_cpu = i;
261 0 : }
262 :
263 0 : g_user_thread_index_start = max_dedicated_cpu + 1;
264 :
265 0 : if (g_user_thread_index_start + num_threads > SPDK_TRACE_MAX_LCORE) {
266 0 : SPDK_ERRLOG("user threads overlap with the threads on dedicated cpus\n");
267 0 : return 1;
268 : }
269 :
270 0 : g_ut_array = spdk_bit_array_create(num_threads);
271 0 : if (!g_ut_array) {
272 0 : SPDK_ERRLOG("could not create bit array for threads\n");
273 0 : return 1;
274 : }
275 :
276 0 : for (i = g_user_thread_index_start; i < g_user_thread_index_start + num_threads; i++) {
277 0 : lcore_offsets[i] = file_size;
278 0 : file_size += spdk_get_trace_history_size(num_entries);
279 0 : }
280 0 : owner_offset = file_size;
281 0 : file_size += TRACE_NUM_OWNERS *
282 : (sizeof(struct spdk_trace_owner) + TRACE_OWNER_DESCRIPTION_SIZE);
283 :
284 0 : snprintf(g_shm_name, sizeof(g_shm_name), "%s", shm_name);
285 :
286 0 : g_trace_fd = shm_open(shm_name, O_RDWR | O_CREAT, 0600);
287 0 : if (g_trace_fd == -1) {
288 0 : SPDK_ERRLOG("could not shm_open spdk_trace\n");
289 0 : SPDK_ERRLOG("errno=%d %s\n", errno, spdk_strerror(errno));
290 0 : spdk_bit_array_free(&g_ut_array);
291 0 : return 1;
292 : }
293 :
294 0 : if (ftruncate(g_trace_fd, file_size) != 0) {
295 0 : SPDK_ERRLOG("could not truncate shm\n");
296 0 : goto trace_init_err;
297 : }
298 :
299 0 : g_trace_file = mmap(NULL, file_size, PROT_READ | PROT_WRITE,
300 0 : MAP_SHARED, g_trace_fd, 0);
301 0 : if (g_trace_file == MAP_FAILED) {
302 0 : SPDK_ERRLOG("could not mmap shm\n");
303 0 : goto trace_init_err;
304 : }
305 :
306 : /* TODO: On FreeBSD, mlock on shm_open'd memory doesn't seem to work. Docs say that kern.ipc.shm_use_phys=1
307 : * should allow it, but forcing that doesn't seem to work either. So for now just skip mlock on FreeBSD
308 : * altogether.
309 : */
310 : #if defined(__linux__)
311 0 : if (mlock(g_trace_file, file_size) != 0) {
312 0 : SPDK_ERRLOG("Could not mlock shm for tracing - %s.\n", spdk_strerror(errno));
313 0 : if (errno == ENOMEM) {
314 0 : SPDK_ERRLOG("Check /dev/shm for old tracing files that can be deleted.\n");
315 0 : }
316 0 : goto trace_init_err;
317 : }
318 : #endif
319 :
320 0 : memset(g_trace_file, 0, file_size);
321 :
322 0 : g_trace_file->tsc_rate = spdk_get_ticks_hz();
323 :
324 0 : for (i = 0; i < SPDK_TRACE_MAX_LCORE; i++) {
325 0 : struct spdk_trace_history *lcore_history;
326 :
327 0 : g_trace_file->lcore_history_offsets[i] = lcore_offsets[i];
328 0 : if (lcore_offsets[i] == 0) {
329 0 : continue;
330 : }
331 :
332 0 : if (i <= max_dedicated_cpu) {
333 0 : assert(spdk_cpuset_get_cpu(&cpuset, i));
334 0 : }
335 :
336 0 : lcore_history = spdk_get_per_lcore_history(g_trace_file, i);
337 0 : lcore_history->lcore = i;
338 0 : lcore_history->num_entries = num_entries;
339 0 : }
340 0 : g_trace_file->file_size = file_size;
341 0 : g_trace_file->num_owners = TRACE_NUM_OWNERS;
342 0 : g_trace_file->owner_description_size = TRACE_OWNER_DESCRIPTION_SIZE;
343 0 : g_trace_file->owner_offset = owner_offset;
344 :
345 0 : if (trace_flags_init()) {
346 0 : goto trace_init_err;
347 : }
348 :
349 0 : return 0;
350 :
351 : trace_init_err:
352 0 : if (g_trace_file != MAP_FAILED) {
353 0 : munmap(g_trace_file, file_size);
354 0 : }
355 0 : close(g_trace_fd);
356 0 : g_trace_fd = -1;
357 0 : shm_unlink(shm_name);
358 0 : spdk_bit_array_free(&g_ut_array);
359 0 : g_trace_file = NULL;
360 :
361 0 : return 1;
362 :
363 0 : }
364 :
365 : void
366 0 : spdk_trace_cleanup(void)
367 : {
368 0 : bool unlink = true;
369 0 : int i;
370 0 : struct spdk_trace_history *lcore_history;
371 :
372 0 : if (g_trace_file == NULL) {
373 0 : return;
374 : }
375 :
376 0 : trace_flags_fini();
377 :
378 : /*
379 : * Only unlink the shm if there were no trace_entry recorded. This ensures the file
380 : * can be used after this process exits/crashes for debugging.
381 : * Note that we have to calculate this value before g_trace_file gets unmapped.
382 : */
383 0 : for (i = 0; i < SPDK_TRACE_MAX_LCORE; i++) {
384 0 : lcore_history = spdk_get_per_lcore_history(g_trace_file, i);
385 0 : if (lcore_history == NULL) {
386 0 : continue;
387 : }
388 0 : unlink = lcore_history->entries[0].tsc == 0;
389 0 : if (!unlink) {
390 0 : break;
391 : }
392 0 : }
393 :
394 0 : munmap(g_trace_file, sizeof(struct spdk_trace_file));
395 0 : g_trace_file = NULL;
396 0 : close(g_trace_fd);
397 0 : spdk_bit_array_free(&g_ut_array);
398 :
399 0 : if (unlink) {
400 0 : shm_unlink(g_shm_name);
401 0 : }
402 0 : }
403 :
404 : const char *
405 0 : trace_get_shm_name(void)
406 : {
407 0 : return g_shm_name;
408 : }
|
