]>
Commit | Line | Data |
---|---|---|
26f7227b SH |
1 | /* |
2 | * Simple trace backend | |
3 | * | |
4 | * Copyright IBM, Corp. 2010 | |
5 | * | |
6 | * This work is licensed under the terms of the GNU GPL, version 2. See | |
7 | * the COPYING file in the top-level directory. | |
8 | * | |
9 | */ | |
10 | ||
11 | #include <stdlib.h> | |
12 | #include <stdint.h> | |
13 | #include <stdio.h> | |
14 | #include <time.h> | |
85aff158 | 15 | #ifndef _WIN32 |
0b5538c3 SH |
16 | #include <signal.h> |
17 | #include <pthread.h> | |
85aff158 | 18 | #endif |
c57c846a | 19 | #include "qemu-timer.h" |
26f7227b | 20 | #include "trace.h" |
e4858974 | 21 | #include "trace/control.h" |
26f7227b SH |
22 | |
23 | /** Trace file header event ID */ | |
24 | #define HEADER_EVENT_ID (~(uint64_t)0) /* avoids conflicting with TraceEventIDs */ | |
25 | ||
26 | /** Trace file magic number */ | |
27 | #define HEADER_MAGIC 0xf2b177cb0aa429b4ULL | |
28 | ||
29 | /** Trace file version number, bump if format changes */ | |
30 | #define HEADER_VERSION 0 | |
31 | ||
0b5538c3 SH |
32 | /** Records were dropped event ID */ |
33 | #define DROPPED_EVENT_ID (~(uint64_t)0 - 1) | |
34 | ||
35 | /** Trace record is valid */ | |
36 | #define TRACE_RECORD_VALID ((uint64_t)1 << 63) | |
37 | ||
26f7227b SH |
38 | /** Trace buffer entry */ |
39 | typedef struct { | |
40 | uint64_t event; | |
41 | uint64_t timestamp_ns; | |
42 | uint64_t x1; | |
43 | uint64_t x2; | |
44 | uint64_t x3; | |
45 | uint64_t x4; | |
46 | uint64_t x5; | |
47 | uint64_t x6; | |
48 | } TraceRecord; | |
49 | ||
50 | enum { | |
0b5538c3 SH |
51 | TRACE_BUF_LEN = 4096, |
52 | TRACE_BUF_FLUSH_THRESHOLD = TRACE_BUF_LEN / 4, | |
26f7227b SH |
53 | }; |
54 | ||
0b5538c3 SH |
55 | /* |
56 | * Trace records are written out by a dedicated thread. The thread waits for | |
57 | * records to become available, writes them out, and then waits again. | |
58 | */ | |
85aff158 SH |
59 | static GStaticMutex trace_lock = G_STATIC_MUTEX_INIT; |
60 | static GCond *trace_available_cond; | |
61 | static GCond *trace_empty_cond; | |
0b5538c3 SH |
62 | static bool trace_available; |
63 | static bool trace_writeout_enabled; | |
64 | ||
26f7227b SH |
65 | static TraceRecord trace_buf[TRACE_BUF_LEN]; |
66 | static unsigned int trace_idx; | |
67 | static FILE *trace_fp; | |
c5ceb523 | 68 | static char *trace_file_name = NULL; |
26f7227b | 69 | |
c5ceb523 | 70 | /** |
0b5538c3 SH |
71 | * Read a trace record from the trace buffer |
72 | * | |
73 | * @idx Trace buffer index | |
74 | * @record Trace record to fill | |
75 | * | |
76 | * Returns false if the record is not valid. | |
c5ceb523 | 77 | */ |
0b5538c3 | 78 | static bool get_trace_record(unsigned int idx, TraceRecord *record) |
9410b56c | 79 | { |
0b5538c3 SH |
80 | if (!(trace_buf[idx].event & TRACE_RECORD_VALID)) { |
81 | return false; | |
9410b56c PS |
82 | } |
83 | ||
0b5538c3 SH |
84 | __sync_synchronize(); /* read memory barrier before accessing record */ |
85 | ||
86 | *record = trace_buf[idx]; | |
87 | record->event &= ~TRACE_RECORD_VALID; | |
c5ceb523 | 88 | return true; |
9410b56c PS |
89 | } |
90 | ||
0b5538c3 SH |
91 | /** |
92 | * Kick writeout thread | |
93 | * | |
94 | * @wait Whether to wait for writeout thread to complete | |
95 | */ | |
96 | static void flush_trace_file(bool wait) | |
26f7227b | 97 | { |
85aff158 | 98 | g_static_mutex_lock(&trace_lock); |
0b5538c3 | 99 | trace_available = true; |
85aff158 | 100 | g_cond_signal(trace_available_cond); |
c5ceb523 | 101 | |
0b5538c3 | 102 | if (wait) { |
85aff158 | 103 | g_cond_wait(trace_empty_cond, g_static_mutex_get_mutex(&trace_lock)); |
26f7227b | 104 | } |
0b5538c3 | 105 | |
85aff158 | 106 | g_static_mutex_unlock(&trace_lock); |
c5ceb523 SH |
107 | } |
108 | ||
0b5538c3 | 109 | static void wait_for_trace_records_available(void) |
c5ceb523 | 110 | { |
85aff158 | 111 | g_static_mutex_lock(&trace_lock); |
0b5538c3 | 112 | while (!(trace_available && trace_writeout_enabled)) { |
85aff158 SH |
113 | g_cond_signal(trace_empty_cond); |
114 | g_cond_wait(trace_available_cond, | |
115 | g_static_mutex_get_mutex(&trace_lock)); | |
c5ceb523 | 116 | } |
0b5538c3 | 117 | trace_available = false; |
85aff158 | 118 | g_static_mutex_unlock(&trace_lock); |
26f7227b SH |
119 | } |
120 | ||
85aff158 | 121 | static gpointer writeout_thread(gpointer opaque) |
26f7227b | 122 | { |
0b5538c3 SH |
123 | TraceRecord record; |
124 | unsigned int writeout_idx = 0; | |
125 | unsigned int num_available, idx; | |
0caf448b | 126 | size_t unused __attribute__ ((unused)); |
0b5538c3 SH |
127 | |
128 | for (;;) { | |
129 | wait_for_trace_records_available(); | |
130 | ||
131 | num_available = trace_idx - writeout_idx; | |
132 | if (num_available > TRACE_BUF_LEN) { | |
133 | record = (TraceRecord){ | |
134 | .event = DROPPED_EVENT_ID, | |
135 | .x1 = num_available, | |
136 | }; | |
137 | unused = fwrite(&record, sizeof(record), 1, trace_fp); | |
138 | writeout_idx += num_available; | |
139 | } | |
26f7227b | 140 | |
0b5538c3 SH |
141 | idx = writeout_idx % TRACE_BUF_LEN; |
142 | while (get_trace_record(idx, &record)) { | |
143 | trace_buf[idx].event = 0; /* clear valid bit */ | |
144 | unused = fwrite(&record, sizeof(record), 1, trace_fp); | |
145 | idx = ++writeout_idx % TRACE_BUF_LEN; | |
146 | } | |
26f7227b | 147 | |
0b5538c3 | 148 | fflush(trace_fp); |
26f7227b | 149 | } |
0b5538c3 | 150 | return NULL; |
26f7227b SH |
151 | } |
152 | ||
153 | static void trace(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, | |
154 | uint64_t x4, uint64_t x5, uint64_t x6) | |
155 | { | |
0b5538c3 SH |
156 | unsigned int idx; |
157 | uint64_t timestamp; | |
26f7227b | 158 | |
22890ab5 PS |
159 | if (!trace_list[event].state) { |
160 | return; | |
161 | } | |
162 | ||
0b5538c3 SH |
163 | timestamp = get_clock(); |
164 | ||
85aff158 | 165 | idx = g_atomic_int_exchange_and_add((gint *)&trace_idx, 1) % TRACE_BUF_LEN; |
0b5538c3 SH |
166 | trace_buf[idx] = (TraceRecord){ |
167 | .event = event, | |
168 | .timestamp_ns = timestamp, | |
169 | .x1 = x1, | |
170 | .x2 = x2, | |
171 | .x3 = x3, | |
172 | .x4 = x4, | |
173 | .x5 = x5, | |
174 | .x6 = x6, | |
175 | }; | |
176 | __sync_synchronize(); /* write barrier before marking as valid */ | |
177 | trace_buf[idx].event |= TRACE_RECORD_VALID; | |
178 | ||
179 | if ((idx + 1) % TRACE_BUF_FLUSH_THRESHOLD == 0) { | |
180 | flush_trace_file(false); | |
26f7227b SH |
181 | } |
182 | } | |
183 | ||
184 | void trace0(TraceEventID event) | |
185 | { | |
186 | trace(event, 0, 0, 0, 0, 0, 0); | |
187 | } | |
188 | ||
189 | void trace1(TraceEventID event, uint64_t x1) | |
190 | { | |
191 | trace(event, x1, 0, 0, 0, 0, 0); | |
192 | } | |
193 | ||
194 | void trace2(TraceEventID event, uint64_t x1, uint64_t x2) | |
195 | { | |
196 | trace(event, x1, x2, 0, 0, 0, 0); | |
197 | } | |
198 | ||
199 | void trace3(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3) | |
200 | { | |
201 | trace(event, x1, x2, x3, 0, 0, 0); | |
202 | } | |
203 | ||
204 | void trace4(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, uint64_t x4) | |
205 | { | |
206 | trace(event, x1, x2, x3, x4, 0, 0); | |
207 | } | |
208 | ||
209 | void trace5(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, uint64_t x4, uint64_t x5) | |
210 | { | |
211 | trace(event, x1, x2, x3, x4, x5, 0); | |
212 | } | |
213 | ||
214 | void trace6(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, uint64_t x4, uint64_t x5, uint64_t x6) | |
215 | { | |
216 | trace(event, x1, x2, x3, x4, x5, x6); | |
217 | } | |
218 | ||
0b5538c3 SH |
219 | void st_set_trace_file_enabled(bool enable) |
220 | { | |
221 | if (enable == !!trace_fp) { | |
222 | return; /* no change */ | |
223 | } | |
224 | ||
225 | /* Halt trace writeout */ | |
226 | flush_trace_file(true); | |
227 | trace_writeout_enabled = false; | |
228 | flush_trace_file(true); | |
229 | ||
230 | if (enable) { | |
231 | static const TraceRecord header = { | |
232 | .event = HEADER_EVENT_ID, | |
233 | .timestamp_ns = HEADER_MAGIC, | |
234 | .x1 = HEADER_VERSION, | |
235 | }; | |
236 | ||
6c2a4074 | 237 | trace_fp = fopen(trace_file_name, "wb"); |
0b5538c3 SH |
238 | if (!trace_fp) { |
239 | return; | |
240 | } | |
241 | ||
242 | if (fwrite(&header, sizeof header, 1, trace_fp) != 1) { | |
243 | fclose(trace_fp); | |
244 | trace_fp = NULL; | |
245 | return; | |
246 | } | |
247 | ||
248 | /* Resume trace writeout */ | |
249 | trace_writeout_enabled = true; | |
250 | flush_trace_file(false); | |
251 | } else { | |
252 | fclose(trace_fp); | |
253 | trace_fp = NULL; | |
254 | } | |
255 | } | |
256 | ||
26f7227b | 257 | /** |
0b5538c3 SH |
258 | * Set the name of a trace file |
259 | * | |
260 | * @file The trace file name or NULL for the default name-<pid> set at | |
261 | * config time | |
26f7227b | 262 | */ |
0b5538c3 | 263 | bool st_set_trace_file(const char *file) |
26f7227b | 264 | { |
0b5538c3 SH |
265 | st_set_trace_file_enabled(false); |
266 | ||
267 | free(trace_file_name); | |
268 | ||
269 | if (!file) { | |
270 | if (asprintf(&trace_file_name, CONFIG_TRACE_FILE, getpid()) < 0) { | |
271 | trace_file_name = NULL; | |
272 | return false; | |
273 | } | |
274 | } else { | |
275 | if (asprintf(&trace_file_name, "%s", file) < 0) { | |
276 | trace_file_name = NULL; | |
277 | return false; | |
278 | } | |
279 | } | |
280 | ||
281 | st_set_trace_file_enabled(true); | |
282 | return true; | |
283 | } | |
284 | ||
285 | void st_print_trace_file_status(FILE *stream, int (*stream_printf)(FILE *stream, const char *fmt, ...)) | |
286 | { | |
287 | stream_printf(stream, "Trace file \"%s\" %s.\n", | |
288 | trace_file_name, trace_fp ? "on" : "off"); | |
26f7227b | 289 | } |
22890ab5 PS |
290 | |
291 | void st_print_trace(FILE *stream, int (*stream_printf)(FILE *stream, const char *fmt, ...)) | |
292 | { | |
293 | unsigned int i; | |
294 | ||
0b5538c3 SH |
295 | for (i = 0; i < TRACE_BUF_LEN; i++) { |
296 | TraceRecord record; | |
297 | ||
298 | if (!get_trace_record(i, &record)) { | |
299 | continue; | |
300 | } | |
a12c668f BS |
301 | stream_printf(stream, "Event %" PRIu64 " : %" PRIx64 " %" PRIx64 |
302 | " %" PRIx64 " %" PRIx64 " %" PRIx64 " %" PRIx64 "\n", | |
0b5538c3 SH |
303 | record.event, record.x1, record.x2, |
304 | record.x3, record.x4, record.x5, | |
305 | record.x6); | |
22890ab5 PS |
306 | } |
307 | } | |
308 | ||
fc764105 LV |
309 | void st_flush_trace_buffer(void) |
310 | { | |
311 | flush_trace_file(true); | |
312 | } | |
313 | ||
314 | void trace_print_events(FILE *stream, fprintf_function stream_printf) | |
22890ab5 PS |
315 | { |
316 | unsigned int i; | |
317 | ||
318 | for (i = 0; i < NR_TRACE_EVENTS; i++) { | |
319 | stream_printf(stream, "%s [Event ID %u] : state %u\n", | |
320 | trace_list[i].tp_name, i, trace_list[i].state); | |
321 | } | |
322 | } | |
323 | ||
fc764105 | 324 | bool trace_event_set_state(const char *name, bool state) |
22890ab5 PS |
325 | { |
326 | unsigned int i; | |
454e202d MW |
327 | unsigned int len; |
328 | bool wildcard = false; | |
329 | bool matched = false; | |
330 | ||
331 | len = strlen(name); | |
332 | if (len > 0 && name[len - 1] == '*') { | |
333 | wildcard = true; | |
334 | len -= 1; | |
335 | } | |
22890ab5 | 336 | for (i = 0; i < NR_TRACE_EVENTS; i++) { |
454e202d MW |
337 | if (wildcard) { |
338 | if (!strncmp(trace_list[i].tp_name, name, len)) { | |
339 | trace_list[i].state = state; | |
340 | matched = true; | |
341 | } | |
342 | continue; | |
343 | } | |
0b5538c3 | 344 | if (!strcmp(trace_list[i].tp_name, name)) { |
fc764105 | 345 | trace_list[i].state = state; |
0b5538c3 | 346 | return true; |
22890ab5 PS |
347 | } |
348 | } | |
454e202d | 349 | return matched; |
0b5538c3 SH |
350 | } |
351 | ||
85aff158 SH |
352 | /* Helper function to create a thread with signals blocked. Use glib's |
353 | * portable threads since QEMU abstractions cannot be used due to reentrancy in | |
354 | * the tracer. Also note the signal masking on POSIX hosts so that the thread | |
355 | * does not steal signals when the rest of the program wants them blocked. | |
356 | */ | |
357 | static GThread *trace_thread_create(GThreadFunc fn) | |
22890ab5 | 358 | { |
85aff158 SH |
359 | GThread *thread; |
360 | #ifndef _WIN32 | |
0b5538c3 | 361 | sigset_t set, oldset; |
22890ab5 | 362 | |
0b5538c3 SH |
363 | sigfillset(&set); |
364 | pthread_sigmask(SIG_SETMASK, &set, &oldset); | |
85aff158 | 365 | #endif |
db3bf869 | 366 | thread = g_thread_create(fn, NULL, FALSE, NULL); |
85aff158 | 367 | #ifndef _WIN32 |
0b5538c3 | 368 | pthread_sigmask(SIG_SETMASK, &oldset, NULL); |
85aff158 | 369 | #endif |
0b5538c3 | 370 | |
85aff158 SH |
371 | return thread; |
372 | } | |
373 | ||
374 | bool trace_backend_init(const char *events, const char *file) | |
375 | { | |
376 | GThread *thread; | |
377 | ||
378 | if (!g_thread_supported()) { | |
42ed3727 | 379 | #if !GLIB_CHECK_VERSION(2, 31, 0) |
85aff158 | 380 | g_thread_init(NULL); |
42ed3727 AL |
381 | #else |
382 | fprintf(stderr, "glib threading failed to initialize.\n"); | |
383 | exit(1); | |
384 | #endif | |
85aff158 SH |
385 | } |
386 | ||
387 | trace_available_cond = g_cond_new(); | |
388 | trace_empty_cond = g_cond_new(); | |
389 | ||
390 | thread = trace_thread_create(writeout_thread); | |
391 | if (!thread) { | |
e4858974 | 392 | fprintf(stderr, "warning: unable to initialize simple trace backend\n"); |
85aff158 | 393 | return false; |
22890ab5 | 394 | } |
0b5538c3 | 395 | |
85aff158 SH |
396 | atexit(st_flush_trace_buffer); |
397 | trace_backend_init_events(events); | |
398 | st_set_trace_file(file); | |
31d3c9b8 | 399 | return true; |
22890ab5 | 400 | } |