1 /* 2 * qsp.c - QEMU Synchronization Profiler 3 * 4 * Copyright (C) 2018, Emilio G. Cota <cota@braap.org> 5 * 6 * License: GNU GPL, version 2 or later. 7 * See the COPYING file in the top-level directory. 8 * 9 * QSP profiles the time spent in synchronization primitives, which can 10 * help diagnose performance problems, e.g. scalability issues when 11 * contention is high. 12 * 13 * The primitives currently supported are mutexes, recursive mutexes and 14 * condition variables. Note that not all related functions are intercepted; 15 * instead we profile only those functions that can have a performance impact, 16 * either due to blocking (e.g. cond_wait, mutex_lock) or cache line 17 * contention (e.g. mutex_lock, mutex_trylock). 18 * 19 * QSP's design focuses on speed and scalability. This is achieved 20 * by having threads do their profiling entirely on thread-local data. 21 * The appropriate thread-local data is found via a QHT, i.e. a concurrent hash 22 * table. To aggregate data in order to generate a report, we iterate over 23 * all entries in the hash table. Depending on the number of threads and 24 * synchronization objects this might be expensive, but note that it is 25 * very rarely called -- reports are generated only when requested by users. 26 * 27 * Reports are generated as a table where each row represents a call site. A 28 * call site is the triplet formed by the __file__ and __LINE__ of the caller 29 * as well as the address of the "object" (i.e. mutex, rec. mutex or condvar) 30 * being operated on. Optionally, call sites that operate on different objects 31 * of the same type can be coalesced, which can be particularly useful when 32 * profiling dynamically-allocated objects. 33 * 34 * Alternative designs considered: 35 * 36 * - Use an off-the-shelf profiler such as mutrace. This is not a viable option 37 * for us because QEMU has __malloc_hook set (by one of the libraries it 38 * uses); leaving this hook unset is required to avoid deadlock in mutrace. 39 * 40 * - Use a glib HT for each thread, protecting each HT with its own lock. 41 * This isn't simpler than the current design, and is 10% slower in the 42 * atomic_add-bench microbenchmark (-m option). 43 * 44 * - For reports, just use a binary tree as we aggregate data, instead of having 45 * an intermediate hash table. This would simplify the code only slightly, but 46 * would perform badly if there were many threads and objects to track. 47 * 48 * - Wrap operations on qsp entries with RCU read-side critical sections, so 49 * that qsp_reset() can delete entries. Unfortunately, the overhead of calling 50 * rcu_read_lock/unlock slows down atomic_add-bench -m by 24%. Having 51 * a snapshot that is updated on qsp_reset() avoids this overhead. 52 * 53 * Related Work: 54 * - Lennart Poettering's mutrace: http://0pointer.de/blog/projects/mutrace.html 55 * - Lozi, David, Thomas, Lawall and Muller. "Remote Core Locking: Migrating 56 * Critical-Section Execution to Improve the Performance of Multithreaded 57 * Applications", USENIX ATC'12. 58 */ 59 #include "qemu/osdep.h" 60 #include "qemu/thread.h" 61 #include "qemu/timer.h" 62 #include "qemu/qht.h" 63 #include "qemu/rcu.h" 64 #include "exec/tb-hash-xx.h" 65 66 enum QSPType { 67 QSP_MUTEX, 68 QSP_BQL_MUTEX, 69 QSP_REC_MUTEX, 70 QSP_CONDVAR, 71 }; 72 73 struct QSPCallSite { 74 const void *obj; 75 const char *file; /* i.e. __FILE__; shortened later */ 76 int line; 77 enum QSPType type; 78 }; 79 typedef struct QSPCallSite QSPCallSite; 80 81 struct QSPEntry { 82 void *thread_ptr; 83 const QSPCallSite *callsite; 84 uint64_t n_acqs; 85 uint64_t ns; 86 unsigned int n_objs; /* count of coalesced objs; only used for reporting */ 87 }; 88 typedef struct QSPEntry QSPEntry; 89 90 struct QSPSnapshot { 91 struct rcu_head rcu; 92 struct qht ht; 93 }; 94 typedef struct QSPSnapshot QSPSnapshot; 95 96 /* initial sizing for hash tables */ 97 #define QSP_INITIAL_SIZE 64 98 99 /* If this file is moved, QSP_REL_PATH should be updated accordingly */ 100 #define QSP_REL_PATH "util/qsp.c" 101 102 /* this file's full path. Used to present all call sites with relative paths */ 103 static size_t qsp_qemu_path_len; 104 105 /* the address of qsp_thread gives us a unique 'thread ID' */ 106 static __thread int qsp_thread; 107 108 /* 109 * Call sites are the same for all threads, so we track them in a separate hash 110 * table to save memory. 111 */ 112 static struct qht qsp_callsite_ht; 113 114 static struct qht qsp_ht; 115 static QSPSnapshot *qsp_snapshot; 116 static bool qsp_initialized, qsp_initializing; 117 118 static const char * const qsp_typenames[] = { 119 [QSP_MUTEX] = "mutex", 120 [QSP_BQL_MUTEX] = "BQL mutex", 121 [QSP_REC_MUTEX] = "rec_mutex", 122 [QSP_CONDVAR] = "condvar", 123 }; 124 125 QemuMutexLockFunc qemu_bql_mutex_lock_func = qemu_mutex_lock_impl; 126 QemuMutexLockFunc qemu_mutex_lock_func = qemu_mutex_lock_impl; 127 QemuMutexTrylockFunc qemu_mutex_trylock_func = qemu_mutex_trylock_impl; 128 QemuRecMutexLockFunc qemu_rec_mutex_lock_func = qemu_rec_mutex_lock_impl; 129 QemuRecMutexTrylockFunc qemu_rec_mutex_trylock_func = 130 qemu_rec_mutex_trylock_impl; 131 QemuCondWaitFunc qemu_cond_wait_func = qemu_cond_wait_impl; 132 133 /* 134 * It pays off to _not_ hash callsite->file; hashing a string is slow, and 135 * without it we still get a pretty unique hash. 136 */ 137 static inline 138 uint32_t do_qsp_callsite_hash(const QSPCallSite *callsite, uint64_t a) 139 { 140 uint64_t b = (uint64_t)(uintptr_t)callsite->obj; 141 uint32_t e = callsite->line; 142 uint32_t f = callsite->type; 143 144 return tb_hash_func7(a, b, e, f, 0); 145 } 146 147 static inline 148 uint32_t qsp_callsite_hash(const QSPCallSite *callsite) 149 { 150 return do_qsp_callsite_hash(callsite, 0); 151 } 152 153 static inline uint32_t do_qsp_entry_hash(const QSPEntry *entry, uint64_t a) 154 { 155 return do_qsp_callsite_hash(entry->callsite, a); 156 } 157 158 static uint32_t qsp_entry_hash(const QSPEntry *entry) 159 { 160 return do_qsp_entry_hash(entry, (uint64_t)(uintptr_t)entry->thread_ptr); 161 } 162 163 static uint32_t qsp_entry_no_thread_hash(const QSPEntry *entry) 164 { 165 return do_qsp_entry_hash(entry, 0); 166 } 167 168 /* without the objects we need to hash the file name to get a decent hash */ 169 static uint32_t qsp_entry_no_thread_obj_hash(const QSPEntry *entry) 170 { 171 const QSPCallSite *callsite = entry->callsite; 172 uint64_t a = g_str_hash(callsite->file); 173 uint64_t b = callsite->line; 174 uint32_t e = callsite->type; 175 176 return tb_hash_func7(a, b, e, 0, 0); 177 } 178 179 static bool qsp_callsite_cmp(const void *ap, const void *bp) 180 { 181 const QSPCallSite *a = ap; 182 const QSPCallSite *b = bp; 183 184 return a == b || 185 (a->obj == b->obj && 186 a->line == b->line && 187 a->type == b->type && 188 (a->file == b->file || !strcmp(a->file, b->file))); 189 } 190 191 static bool qsp_callsite_no_obj_cmp(const void *ap, const void *bp) 192 { 193 const QSPCallSite *a = ap; 194 const QSPCallSite *b = bp; 195 196 return a == b || 197 (a->line == b->line && 198 a->type == b->type && 199 (a->file == b->file || !strcmp(a->file, b->file))); 200 } 201 202 static bool qsp_entry_no_thread_cmp(const void *ap, const void *bp) 203 { 204 const QSPEntry *a = ap; 205 const QSPEntry *b = bp; 206 207 return qsp_callsite_cmp(a->callsite, b->callsite); 208 } 209 210 static bool qsp_entry_no_thread_obj_cmp(const void *ap, const void *bp) 211 { 212 const QSPEntry *a = ap; 213 const QSPEntry *b = bp; 214 215 return qsp_callsite_no_obj_cmp(a->callsite, b->callsite); 216 } 217 218 static bool qsp_entry_cmp(const void *ap, const void *bp) 219 { 220 const QSPEntry *a = ap; 221 const QSPEntry *b = bp; 222 223 return a->thread_ptr == b->thread_ptr && 224 qsp_callsite_cmp(a->callsite, b->callsite); 225 } 226 227 /* 228 * Normally we'd call this from a constructor function, but we want it to work 229 * via libutil as well. 230 */ 231 static void qsp_do_init(void) 232 { 233 /* make sure this file's path in the tree is up to date with QSP_REL_PATH */ 234 g_assert(strstr(__FILE__, QSP_REL_PATH)); 235 qsp_qemu_path_len = strlen(__FILE__) - strlen(QSP_REL_PATH); 236 237 qht_init(&qsp_ht, qsp_entry_cmp, QSP_INITIAL_SIZE, 238 QHT_MODE_AUTO_RESIZE | QHT_MODE_RAW_MUTEXES); 239 qht_init(&qsp_callsite_ht, qsp_callsite_cmp, QSP_INITIAL_SIZE, 240 QHT_MODE_AUTO_RESIZE | QHT_MODE_RAW_MUTEXES); 241 } 242 243 static __attribute__((noinline)) void qsp_init__slowpath(void) 244 { 245 if (atomic_cmpxchg(&qsp_initializing, false, true) == false) { 246 qsp_do_init(); 247 atomic_set(&qsp_initialized, true); 248 } else { 249 while (!atomic_read(&qsp_initialized)) { 250 cpu_relax(); 251 } 252 } 253 } 254 255 /* qsp_init() must be called from _all_ exported functions */ 256 static inline void qsp_init(void) 257 { 258 if (likely(atomic_read(&qsp_initialized))) { 259 return; 260 } 261 qsp_init__slowpath(); 262 } 263 264 static QSPCallSite *qsp_callsite_find(const QSPCallSite *orig) 265 { 266 QSPCallSite *callsite; 267 uint32_t hash; 268 269 hash = qsp_callsite_hash(orig); 270 callsite = qht_lookup(&qsp_callsite_ht, orig, hash); 271 if (callsite == NULL) { 272 void *existing = NULL; 273 274 callsite = g_new(QSPCallSite, 1); 275 memcpy(callsite, orig, sizeof(*callsite)); 276 qht_insert(&qsp_callsite_ht, callsite, hash, &existing); 277 if (unlikely(existing)) { 278 g_free(callsite); 279 callsite = existing; 280 } 281 } 282 return callsite; 283 } 284 285 static QSPEntry * 286 qsp_entry_create(struct qht *ht, const QSPEntry *entry, uint32_t hash) 287 { 288 QSPEntry *e; 289 void *existing = NULL; 290 291 e = g_new0(QSPEntry, 1); 292 e->thread_ptr = entry->thread_ptr; 293 e->callsite = qsp_callsite_find(entry->callsite); 294 295 qht_insert(ht, e, hash, &existing); 296 if (unlikely(existing)) { 297 g_free(e); 298 e = existing; 299 } 300 return e; 301 } 302 303 static QSPEntry * 304 qsp_entry_find(struct qht *ht, const QSPEntry *entry, uint32_t hash) 305 { 306 QSPEntry *e; 307 308 e = qht_lookup(ht, entry, hash); 309 if (e == NULL) { 310 e = qsp_entry_create(ht, entry, hash); 311 } 312 return e; 313 } 314 315 /* 316 * Note: Entries are never removed, so callers do not have to be in an RCU 317 * read-side critical section. 318 */ 319 static QSPEntry *qsp_entry_get(const void *obj, const char *file, int line, 320 enum QSPType type) 321 { 322 QSPCallSite callsite = { 323 .obj = obj, 324 .file = file, 325 .line = line, 326 .type = type, 327 }; 328 QSPEntry orig; 329 uint32_t hash; 330 331 qsp_init(); 332 333 orig.thread_ptr = &qsp_thread; 334 orig.callsite = &callsite; 335 336 hash = qsp_entry_hash(&orig); 337 return qsp_entry_find(&qsp_ht, &orig, hash); 338 } 339 340 /* 341 * @e is in the global hash table; it is only written to by the current thread, 342 * so we write to it atomically (as in "write once") to prevent torn reads. 343 */ 344 static inline void do_qsp_entry_record(QSPEntry *e, int64_t delta, bool acq) 345 { 346 atomic_set_u64(&e->ns, e->ns + delta); 347 if (acq) { 348 atomic_set_u64(&e->n_acqs, e->n_acqs + 1); 349 } 350 } 351 352 static inline void qsp_entry_record(QSPEntry *e, int64_t delta) 353 { 354 do_qsp_entry_record(e, delta, true); 355 } 356 357 #define QSP_GEN_VOID(type_, qsp_t_, func_, impl_) \ 358 static void func_(type_ *obj, const char *file, int line) \ 359 { \ 360 QSPEntry *e; \ 361 int64_t t0, t1; \ 362 \ 363 t0 = get_clock(); \ 364 impl_(obj, file, line); \ 365 t1 = get_clock(); \ 366 \ 367 e = qsp_entry_get(obj, file, line, qsp_t_); \ 368 qsp_entry_record(e, t1 - t0); \ 369 } 370 371 #define QSP_GEN_RET1(type_, qsp_t_, func_, impl_) \ 372 static int func_(type_ *obj, const char *file, int line) \ 373 { \ 374 QSPEntry *e; \ 375 int64_t t0, t1; \ 376 int err; \ 377 \ 378 t0 = get_clock(); \ 379 err = impl_(obj, file, line); \ 380 t1 = get_clock(); \ 381 \ 382 e = qsp_entry_get(obj, file, line, qsp_t_); \ 383 do_qsp_entry_record(e, t1 - t0, !err); \ 384 return err; \ 385 } 386 387 QSP_GEN_VOID(QemuMutex, QSP_BQL_MUTEX, qsp_bql_mutex_lock, qemu_mutex_lock_impl) 388 QSP_GEN_VOID(QemuMutex, QSP_MUTEX, qsp_mutex_lock, qemu_mutex_lock_impl) 389 QSP_GEN_RET1(QemuMutex, QSP_MUTEX, qsp_mutex_trylock, qemu_mutex_trylock_impl) 390 391 QSP_GEN_VOID(QemuRecMutex, QSP_REC_MUTEX, qsp_rec_mutex_lock, 392 qemu_rec_mutex_lock_impl) 393 QSP_GEN_RET1(QemuRecMutex, QSP_REC_MUTEX, qsp_rec_mutex_trylock, 394 qemu_rec_mutex_trylock_impl) 395 396 #undef QSP_GEN_RET1 397 #undef QSP_GEN_VOID 398 399 static void 400 qsp_cond_wait(QemuCond *cond, QemuMutex *mutex, const char *file, int line) 401 { 402 QSPEntry *e; 403 int64_t t0, t1; 404 405 t0 = get_clock(); 406 qemu_cond_wait_impl(cond, mutex, file, line); 407 t1 = get_clock(); 408 409 e = qsp_entry_get(cond, file, line, QSP_CONDVAR); 410 qsp_entry_record(e, t1 - t0); 411 } 412 413 bool qsp_is_enabled(void) 414 { 415 return atomic_read(&qemu_mutex_lock_func) == qsp_mutex_lock; 416 } 417 418 void qsp_enable(void) 419 { 420 atomic_set(&qemu_mutex_lock_func, qsp_mutex_lock); 421 atomic_set(&qemu_mutex_trylock_func, qsp_mutex_trylock); 422 atomic_set(&qemu_bql_mutex_lock_func, qsp_bql_mutex_lock); 423 atomic_set(&qemu_rec_mutex_lock_func, qsp_rec_mutex_lock); 424 atomic_set(&qemu_rec_mutex_trylock_func, qsp_rec_mutex_trylock); 425 atomic_set(&qemu_cond_wait_func, qsp_cond_wait); 426 } 427 428 void qsp_disable(void) 429 { 430 atomic_set(&qemu_mutex_lock_func, qemu_mutex_lock_impl); 431 atomic_set(&qemu_mutex_trylock_func, qemu_mutex_trylock_impl); 432 atomic_set(&qemu_bql_mutex_lock_func, qemu_mutex_lock_impl); 433 atomic_set(&qemu_rec_mutex_lock_func, qemu_rec_mutex_lock_impl); 434 atomic_set(&qemu_rec_mutex_trylock_func, qemu_rec_mutex_trylock_impl); 435 atomic_set(&qemu_cond_wait_func, qemu_cond_wait_impl); 436 } 437 438 static gint qsp_tree_cmp(gconstpointer ap, gconstpointer bp, gpointer up) 439 { 440 const QSPEntry *a = ap; 441 const QSPEntry *b = bp; 442 enum QSPSortBy sort_by = *(enum QSPSortBy *)up; 443 const QSPCallSite *ca; 444 const QSPCallSite *cb; 445 446 switch (sort_by) { 447 case QSP_SORT_BY_TOTAL_WAIT_TIME: 448 if (a->ns > b->ns) { 449 return -1; 450 } else if (a->ns < b->ns) { 451 return 1; 452 } 453 break; 454 case QSP_SORT_BY_AVG_WAIT_TIME: 455 { 456 double avg_a = a->n_acqs ? a->ns / a->n_acqs : 0; 457 double avg_b = b->n_acqs ? b->ns / b->n_acqs : 0; 458 459 if (avg_a > avg_b) { 460 return -1; 461 } else if (avg_a < avg_b) { 462 return 1; 463 } 464 break; 465 } 466 default: 467 g_assert_not_reached(); 468 } 469 470 ca = a->callsite; 471 cb = b->callsite; 472 /* Break the tie with the object's address */ 473 if (ca->obj < cb->obj) { 474 return -1; 475 } else if (ca->obj > cb->obj) { 476 return 1; 477 } else { 478 int cmp; 479 480 /* same obj. Break the tie with the callsite's file */ 481 cmp = strcmp(ca->file, cb->file); 482 if (cmp) { 483 return cmp; 484 } 485 /* same callsite file. Break the tie with the callsite's line */ 486 g_assert(ca->line != cb->line); 487 if (ca->line < cb->line) { 488 return -1; 489 } else if (ca->line > cb->line) { 490 return 1; 491 } else { 492 /* break the tie with the callsite's type */ 493 return cb->type - ca->type; 494 } 495 } 496 } 497 498 static void qsp_sort(void *p, uint32_t h, void *userp) 499 { 500 QSPEntry *e = p; 501 GTree *tree = userp; 502 503 g_tree_insert(tree, e, NULL); 504 } 505 506 static void qsp_aggregate(void *p, uint32_t h, void *up) 507 { 508 struct qht *ht = up; 509 const QSPEntry *e = p; 510 QSPEntry *agg; 511 uint32_t hash; 512 513 hash = qsp_entry_no_thread_hash(e); 514 agg = qsp_entry_find(ht, e, hash); 515 /* 516 * The entry is in the global hash table; read from it atomically (as in 517 * "read once"). 518 */ 519 agg->ns += atomic_read_u64(&e->ns); 520 agg->n_acqs += atomic_read_u64(&e->n_acqs); 521 } 522 523 static void qsp_iter_diff(void *p, uint32_t hash, void *htp) 524 { 525 struct qht *ht = htp; 526 QSPEntry *old = p; 527 QSPEntry *new; 528 529 new = qht_lookup(ht, old, hash); 530 /* entries are never deleted, so we must have this one */ 531 g_assert(new != NULL); 532 /* our reading of the stats happened after the snapshot was taken */ 533 g_assert(new->n_acqs >= old->n_acqs); 534 g_assert(new->ns >= old->ns); 535 536 new->n_acqs -= old->n_acqs; 537 new->ns -= old->ns; 538 539 /* No point in reporting an empty entry */ 540 if (new->n_acqs == 0 && new->ns == 0) { 541 bool removed = qht_remove(ht, new, hash); 542 543 g_assert(removed); 544 g_free(new); 545 } 546 } 547 548 static void qsp_diff(struct qht *orig, struct qht *new) 549 { 550 qht_iter(orig, qsp_iter_diff, new); 551 } 552 553 static void qsp_iter_callsite_coalesce(void *p, uint32_t h, void *htp) 554 { 555 struct qht *ht = htp; 556 QSPEntry *old = p; 557 QSPEntry *e; 558 uint32_t hash; 559 560 hash = qsp_entry_no_thread_obj_hash(old); 561 e = qht_lookup(ht, old, hash); 562 if (e == NULL) { 563 e = qsp_entry_create(ht, old, hash); 564 e->n_objs = 1; 565 } else if (e->callsite->obj != old->callsite->obj) { 566 e->n_objs++; 567 } 568 e->ns += old->ns; 569 e->n_acqs += old->n_acqs; 570 } 571 572 static void qsp_ht_delete(void *p, uint32_t h, void *htp) 573 { 574 g_free(p); 575 } 576 577 static void qsp_mktree(GTree *tree, bool callsite_coalesce) 578 { 579 QSPSnapshot *snap; 580 struct qht ht, coalesce_ht; 581 struct qht *htp; 582 583 /* 584 * First, see if there's a prior snapshot, so that we read the global hash 585 * table _after_ the snapshot has been created, which guarantees that 586 * the entries we'll read will be a superset of the snapshot's entries. 587 * 588 * We must remain in an RCU read-side critical section until we're done 589 * with the snapshot. 590 */ 591 rcu_read_lock(); 592 snap = atomic_rcu_read(&qsp_snapshot); 593 594 /* Aggregate all results from the global hash table into a local one */ 595 qht_init(&ht, qsp_entry_no_thread_cmp, QSP_INITIAL_SIZE, 596 QHT_MODE_AUTO_RESIZE | QHT_MODE_RAW_MUTEXES); 597 qht_iter(&qsp_ht, qsp_aggregate, &ht); 598 599 /* compute the difference wrt the snapshot, if any */ 600 if (snap) { 601 qsp_diff(&snap->ht, &ht); 602 } 603 /* done with the snapshot; RCU can reclaim it */ 604 rcu_read_unlock(); 605 606 htp = &ht; 607 if (callsite_coalesce) { 608 qht_init(&coalesce_ht, qsp_entry_no_thread_obj_cmp, QSP_INITIAL_SIZE, 609 QHT_MODE_AUTO_RESIZE | QHT_MODE_RAW_MUTEXES); 610 qht_iter(&ht, qsp_iter_callsite_coalesce, &coalesce_ht); 611 612 /* free the previous hash table, and point htp to coalesce_ht */ 613 qht_iter(&ht, qsp_ht_delete, NULL); 614 qht_destroy(&ht); 615 htp = &coalesce_ht; 616 } 617 618 /* sort the hash table elements by using a tree */ 619 qht_iter(htp, qsp_sort, tree); 620 621 /* free the hash table, but keep the elements (those are in the tree now) */ 622 qht_destroy(htp); 623 } 624 625 /* free string with g_free */ 626 static char *qsp_at(const QSPCallSite *callsite) 627 { 628 GString *s = g_string_new(NULL); 629 const char *shortened; 630 631 /* remove the absolute path to qemu */ 632 if (unlikely(strlen(callsite->file) < qsp_qemu_path_len)) { 633 shortened = callsite->file; 634 } else { 635 shortened = callsite->file + qsp_qemu_path_len; 636 } 637 g_string_append_printf(s, "%s:%u", shortened, callsite->line); 638 return g_string_free(s, FALSE); 639 } 640 641 struct QSPReportEntry { 642 const void *obj; 643 char *callsite_at; 644 const char *typename; 645 double time_s; 646 double ns_avg; 647 uint64_t n_acqs; 648 unsigned int n_objs; 649 }; 650 typedef struct QSPReportEntry QSPReportEntry; 651 652 struct QSPReport { 653 QSPReportEntry *entries; 654 size_t n_entries; 655 size_t max_n_entries; 656 }; 657 typedef struct QSPReport QSPReport; 658 659 static gboolean qsp_tree_report(gpointer key, gpointer value, gpointer udata) 660 { 661 const QSPEntry *e = key; 662 QSPReport *report = udata; 663 QSPReportEntry *entry; 664 665 if (report->n_entries == report->max_n_entries) { 666 return TRUE; 667 } 668 entry = &report->entries[report->n_entries]; 669 report->n_entries++; 670 671 entry->obj = e->callsite->obj; 672 entry->n_objs = e->n_objs; 673 entry->callsite_at = qsp_at(e->callsite); 674 entry->typename = qsp_typenames[e->callsite->type]; 675 entry->time_s = e->ns * 1e-9; 676 entry->n_acqs = e->n_acqs; 677 entry->ns_avg = e->n_acqs ? e->ns / e->n_acqs : 0; 678 return FALSE; 679 } 680 681 static void 682 pr_report(const QSPReport *rep, FILE *f, fprintf_function pr) 683 { 684 char *dashes; 685 size_t max_len = 0; 686 int callsite_len = 0; 687 int callsite_rspace; 688 int n_dashes; 689 size_t i; 690 691 /* find out the maximum length of all 'callsite' fields */ 692 for (i = 0; i < rep->n_entries; i++) { 693 const QSPReportEntry *e = &rep->entries[i]; 694 size_t len = strlen(e->callsite_at); 695 696 if (len > max_len) { 697 max_len = len; 698 } 699 } 700 701 callsite_len = MAX(max_len, strlen("Call site")); 702 /* white space to leave to the right of "Call site" */ 703 callsite_rspace = callsite_len - strlen("Call site"); 704 705 pr(f, "Type Object Call site%*s Wait Time (s) " 706 " Count Average (us)\n", callsite_rspace, ""); 707 708 /* build a horizontal rule with dashes */ 709 n_dashes = 79 + callsite_rspace; 710 dashes = g_malloc(n_dashes + 1); 711 memset(dashes, '-', n_dashes); 712 dashes[n_dashes] = '\0'; 713 pr(f, "%s\n", dashes); 714 715 for (i = 0; i < rep->n_entries; i++) { 716 const QSPReportEntry *e = &rep->entries[i]; 717 GString *s = g_string_new(NULL); 718 719 g_string_append_printf(s, "%-9s ", e->typename); 720 if (e->n_objs > 1) { 721 g_string_append_printf(s, "[%12u]", e->n_objs); 722 } else { 723 g_string_append_printf(s, "%14p", e->obj); 724 } 725 g_string_append_printf(s, " %s%*s %13.5f %12" PRIu64 " %12.2f\n", 726 e->callsite_at, 727 callsite_len - (int)strlen(e->callsite_at), "", 728 e->time_s, e->n_acqs, e->ns_avg * 1e-3); 729 pr(f, "%s", s->str); 730 g_string_free(s, TRUE); 731 } 732 733 pr(f, "%s\n", dashes); 734 g_free(dashes); 735 } 736 737 static void report_destroy(QSPReport *rep) 738 { 739 size_t i; 740 741 for (i = 0; i < rep->n_entries; i++) { 742 QSPReportEntry *e = &rep->entries[i]; 743 744 g_free(e->callsite_at); 745 } 746 g_free(rep->entries); 747 } 748 749 void qsp_report(FILE *f, fprintf_function cpu_fprintf, size_t max, 750 enum QSPSortBy sort_by, bool callsite_coalesce) 751 { 752 GTree *tree = g_tree_new_full(qsp_tree_cmp, &sort_by, g_free, NULL); 753 QSPReport rep; 754 755 qsp_init(); 756 757 rep.entries = g_new0(QSPReportEntry, max); 758 rep.n_entries = 0; 759 rep.max_n_entries = max; 760 761 qsp_mktree(tree, callsite_coalesce); 762 g_tree_foreach(tree, qsp_tree_report, &rep); 763 g_tree_destroy(tree); 764 765 pr_report(&rep, f, cpu_fprintf); 766 report_destroy(&rep); 767 } 768 769 static void qsp_snapshot_destroy(QSPSnapshot *snap) 770 { 771 qht_iter(&snap->ht, qsp_ht_delete, NULL); 772 qht_destroy(&snap->ht); 773 g_free(snap); 774 } 775 776 void qsp_reset(void) 777 { 778 QSPSnapshot *new = g_new(QSPSnapshot, 1); 779 QSPSnapshot *old; 780 781 qsp_init(); 782 783 qht_init(&new->ht, qsp_entry_cmp, QSP_INITIAL_SIZE, 784 QHT_MODE_AUTO_RESIZE | QHT_MODE_RAW_MUTEXES); 785 786 /* take a snapshot of the current state */ 787 qht_iter(&qsp_ht, qsp_aggregate, &new->ht); 788 789 /* replace the previous snapshot, if any */ 790 old = atomic_xchg(&qsp_snapshot, new); 791 if (old) { 792 call_rcu(old, qsp_snapshot_destroy, rcu); 793 } 794 } 795