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