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