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