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