Revision 0b5538c3 simpletrace.c
b/simpletrace.c | ||
---|---|---|
12 | 12 |
#include <stdint.h> |
13 | 13 |
#include <stdio.h> |
14 | 14 |
#include <time.h> |
15 |
#include <signal.h> |
|
16 |
#include <pthread.h> |
|
17 |
#include "qerror.h" |
|
15 | 18 |
#include "qemu-timer.h" |
16 | 19 |
#include "trace.h" |
17 | 20 |
|
... | ... | |
24 | 27 |
/** Trace file version number, bump if format changes */ |
25 | 28 |
#define HEADER_VERSION 0 |
26 | 29 |
|
30 |
/** Records were dropped event ID */ |
|
31 |
#define DROPPED_EVENT_ID (~(uint64_t)0 - 1) |
|
32 |
|
|
33 |
/** Trace record is valid */ |
|
34 |
#define TRACE_RECORD_VALID ((uint64_t)1 << 63) |
|
35 |
|
|
27 | 36 |
/** Trace buffer entry */ |
28 | 37 |
typedef struct { |
29 | 38 |
uint64_t event; |
... | ... | |
37 | 46 |
} TraceRecord; |
38 | 47 |
|
39 | 48 |
enum { |
40 |
TRACE_BUF_LEN = 64 * 1024 / sizeof(TraceRecord), |
|
49 |
TRACE_BUF_LEN = 4096, |
|
50 |
TRACE_BUF_FLUSH_THRESHOLD = TRACE_BUF_LEN / 4, |
|
41 | 51 |
}; |
42 | 52 |
|
53 |
/* |
|
54 |
* Trace records are written out by a dedicated thread. The thread waits for |
|
55 |
* records to become available, writes them out, and then waits again. |
|
56 |
*/ |
|
57 |
static pthread_mutex_t trace_lock = PTHREAD_MUTEX_INITIALIZER; |
|
58 |
static pthread_cond_t trace_available_cond = PTHREAD_COND_INITIALIZER; |
|
59 |
static pthread_cond_t trace_empty_cond = PTHREAD_COND_INITIALIZER; |
|
60 |
static bool trace_available; |
|
61 |
static bool trace_writeout_enabled; |
|
62 |
|
|
43 | 63 |
static TraceRecord trace_buf[TRACE_BUF_LEN]; |
44 | 64 |
static unsigned int trace_idx; |
45 | 65 |
static FILE *trace_fp; |
46 | 66 |
static char *trace_file_name = NULL; |
47 |
static bool trace_file_enabled = false; |
|
48 |
|
|
49 |
void st_print_trace_file_status(FILE *stream, int (*stream_printf)(FILE *stream, const char *fmt, ...)) |
|
50 |
{ |
|
51 |
stream_printf(stream, "Trace file \"%s\" %s.\n", |
|
52 |
trace_file_name, trace_file_enabled ? "on" : "off"); |
|
53 |
} |
|
54 |
|
|
55 |
static bool write_header(FILE *fp) |
|
56 |
{ |
|
57 |
static const TraceRecord header = { |
|
58 |
.event = HEADER_EVENT_ID, |
|
59 |
.timestamp_ns = HEADER_MAGIC, |
|
60 |
.x1 = HEADER_VERSION, |
|
61 |
}; |
|
62 |
|
|
63 |
return fwrite(&header, sizeof header, 1, fp) == 1; |
|
64 |
} |
|
65 | 67 |
|
66 | 68 |
/** |
67 |
* set_trace_file : To set the name of a trace file. |
|
68 |
* @file : pointer to the name to be set. |
|
69 |
* If NULL, set to the default name-<pid> set at config time. |
|
69 |
* Read a trace record from the trace buffer |
|
70 |
* |
|
71 |
* @idx Trace buffer index |
|
72 |
* @record Trace record to fill |
|
73 |
* |
|
74 |
* Returns false if the record is not valid. |
|
70 | 75 |
*/ |
71 |
bool st_set_trace_file(const char *file)
|
|
76 |
static bool get_trace_record(unsigned int idx, TraceRecord *record)
|
|
72 | 77 |
{ |
73 |
st_set_trace_file_enabled(false); |
|
74 |
|
|
75 |
free(trace_file_name); |
|
76 |
|
|
77 |
if (!file) { |
|
78 |
if (asprintf(&trace_file_name, CONFIG_TRACE_FILE, getpid()) < 0) { |
|
79 |
trace_file_name = NULL; |
|
80 |
return false; |
|
81 |
} |
|
82 |
} else { |
|
83 |
if (asprintf(&trace_file_name, "%s", file) < 0) { |
|
84 |
trace_file_name = NULL; |
|
85 |
return false; |
|
86 |
} |
|
78 |
if (!(trace_buf[idx].event & TRACE_RECORD_VALID)) { |
|
79 |
return false; |
|
87 | 80 |
} |
88 | 81 |
|
89 |
st_set_trace_file_enabled(true); |
|
82 |
__sync_synchronize(); /* read memory barrier before accessing record */ |
|
83 |
|
|
84 |
*record = trace_buf[idx]; |
|
85 |
record->event &= ~TRACE_RECORD_VALID; |
|
90 | 86 |
return true; |
91 | 87 |
} |
92 | 88 |
|
93 |
static void flush_trace_file(void) |
|
89 |
/** |
|
90 |
* Kick writeout thread |
|
91 |
* |
|
92 |
* @wait Whether to wait for writeout thread to complete |
|
93 |
*/ |
|
94 |
static void flush_trace_file(bool wait) |
|
94 | 95 |
{ |
95 |
/* If the trace file is not open yet, open it now */ |
|
96 |
if (!trace_fp) { |
|
97 |
trace_fp = fopen(trace_file_name, "w"); |
|
98 |
if (!trace_fp) { |
|
99 |
/* Avoid repeatedly trying to open file on failure */ |
|
100 |
trace_file_enabled = false; |
|
101 |
return; |
|
102 |
} |
|
103 |
write_header(trace_fp); |
|
104 |
} |
|
96 |
pthread_mutex_lock(&trace_lock); |
|
97 |
trace_available = true; |
|
98 |
pthread_cond_signal(&trace_available_cond); |
|
105 | 99 |
|
106 |
if (trace_fp) { |
|
107 |
size_t unused; /* for when fwrite(3) is declared warn_unused_result */ |
|
108 |
unused = fwrite(trace_buf, trace_idx * sizeof(trace_buf[0]), 1, trace_fp); |
|
100 |
if (wait) { |
|
101 |
pthread_cond_wait(&trace_empty_cond, &trace_lock); |
|
109 | 102 |
} |
103 |
|
|
104 |
pthread_mutex_unlock(&trace_lock); |
|
110 | 105 |
} |
111 | 106 |
|
112 |
void st_flush_trace_buffer(void)
|
|
107 |
static void wait_for_trace_records_available(void)
|
|
113 | 108 |
{ |
114 |
if (trace_file_enabled) { |
|
115 |
flush_trace_file(); |
|
109 |
pthread_mutex_lock(&trace_lock); |
|
110 |
while (!(trace_available && trace_writeout_enabled)) { |
|
111 |
pthread_cond_signal(&trace_empty_cond); |
|
112 |
pthread_cond_wait(&trace_available_cond, &trace_lock); |
|
116 | 113 |
} |
117 |
|
|
118 |
/* Discard written trace records */ |
|
119 |
trace_idx = 0; |
|
114 |
trace_available = false; |
|
115 |
pthread_mutex_unlock(&trace_lock); |
|
120 | 116 |
} |
121 | 117 |
|
122 |
void st_set_trace_file_enabled(bool enable)
|
|
118 |
static void *writeout_thread(void *opaque)
|
|
123 | 119 |
{ |
124 |
if (enable == trace_file_enabled) { |
|
125 |
return; /* no change */ |
|
126 |
} |
|
120 |
TraceRecord record; |
|
121 |
unsigned int writeout_idx = 0; |
|
122 |
unsigned int num_available, idx; |
|
123 |
size_t unused; |
|
124 |
|
|
125 |
for (;;) { |
|
126 |
wait_for_trace_records_available(); |
|
127 |
|
|
128 |
num_available = trace_idx - writeout_idx; |
|
129 |
if (num_available > TRACE_BUF_LEN) { |
|
130 |
record = (TraceRecord){ |
|
131 |
.event = DROPPED_EVENT_ID, |
|
132 |
.x1 = num_available, |
|
133 |
}; |
|
134 |
unused = fwrite(&record, sizeof(record), 1, trace_fp); |
|
135 |
writeout_idx += num_available; |
|
136 |
} |
|
127 | 137 |
|
128 |
/* Flush/discard trace buffer */ |
|
129 |
st_flush_trace_buffer(); |
|
138 |
idx = writeout_idx % TRACE_BUF_LEN; |
|
139 |
while (get_trace_record(idx, &record)) { |
|
140 |
trace_buf[idx].event = 0; /* clear valid bit */ |
|
141 |
unused = fwrite(&record, sizeof(record), 1, trace_fp); |
|
142 |
idx = ++writeout_idx % TRACE_BUF_LEN; |
|
143 |
} |
|
130 | 144 |
|
131 |
/* To disable, close trace file */ |
|
132 |
if (!enable) { |
|
133 |
fclose(trace_fp); |
|
134 |
trace_fp = NULL; |
|
145 |
fflush(trace_fp); |
|
135 | 146 |
} |
136 |
|
|
137 |
trace_file_enabled = enable; |
|
147 |
return NULL; |
|
138 | 148 |
} |
139 | 149 |
|
140 | 150 |
static void trace(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, |
141 | 151 |
uint64_t x4, uint64_t x5, uint64_t x6) |
142 | 152 |
{ |
143 |
TraceRecord *rec = &trace_buf[trace_idx]; |
|
153 |
unsigned int idx; |
|
154 |
uint64_t timestamp; |
|
144 | 155 |
|
145 | 156 |
if (!trace_list[event].state) { |
146 | 157 |
return; |
147 | 158 |
} |
148 | 159 |
|
149 |
rec->event = event; |
|
150 |
rec->timestamp_ns = get_clock(); |
|
151 |
rec->x1 = x1; |
|
152 |
rec->x2 = x2; |
|
153 |
rec->x3 = x3; |
|
154 |
rec->x4 = x4; |
|
155 |
rec->x5 = x5; |
|
156 |
rec->x6 = x6; |
|
157 |
|
|
158 |
if (++trace_idx == TRACE_BUF_LEN) { |
|
159 |
st_flush_trace_buffer(); |
|
160 |
timestamp = get_clock(); |
|
161 |
|
|
162 |
idx = __sync_fetch_and_add(&trace_idx, 1) % TRACE_BUF_LEN; |
|
163 |
trace_buf[idx] = (TraceRecord){ |
|
164 |
.event = event, |
|
165 |
.timestamp_ns = timestamp, |
|
166 |
.x1 = x1, |
|
167 |
.x2 = x2, |
|
168 |
.x3 = x3, |
|
169 |
.x4 = x4, |
|
170 |
.x5 = x5, |
|
171 |
.x6 = x6, |
|
172 |
}; |
|
173 |
__sync_synchronize(); /* write barrier before marking as valid */ |
|
174 |
trace_buf[idx].event |= TRACE_RECORD_VALID; |
|
175 |
|
|
176 |
if ((idx + 1) % TRACE_BUF_FLUSH_THRESHOLD == 0) { |
|
177 |
flush_trace_file(false); |
|
160 | 178 |
} |
161 | 179 |
} |
162 | 180 |
|
... | ... | |
195 | 213 |
trace(event, x1, x2, x3, x4, x5, x6); |
196 | 214 |
} |
197 | 215 |
|
216 |
void st_set_trace_file_enabled(bool enable) |
|
217 |
{ |
|
218 |
if (enable == !!trace_fp) { |
|
219 |
return; /* no change */ |
|
220 |
} |
|
221 |
|
|
222 |
/* Halt trace writeout */ |
|
223 |
flush_trace_file(true); |
|
224 |
trace_writeout_enabled = false; |
|
225 |
flush_trace_file(true); |
|
226 |
|
|
227 |
if (enable) { |
|
228 |
static const TraceRecord header = { |
|
229 |
.event = HEADER_EVENT_ID, |
|
230 |
.timestamp_ns = HEADER_MAGIC, |
|
231 |
.x1 = HEADER_VERSION, |
|
232 |
}; |
|
233 |
|
|
234 |
trace_fp = fopen(trace_file_name, "w"); |
|
235 |
if (!trace_fp) { |
|
236 |
return; |
|
237 |
} |
|
238 |
|
|
239 |
if (fwrite(&header, sizeof header, 1, trace_fp) != 1) { |
|
240 |
fclose(trace_fp); |
|
241 |
trace_fp = NULL; |
|
242 |
return; |
|
243 |
} |
|
244 |
|
|
245 |
/* Resume trace writeout */ |
|
246 |
trace_writeout_enabled = true; |
|
247 |
flush_trace_file(false); |
|
248 |
} else { |
|
249 |
fclose(trace_fp); |
|
250 |
trace_fp = NULL; |
|
251 |
} |
|
252 |
} |
|
253 |
|
|
198 | 254 |
/** |
199 |
* Flush the trace buffer on exit |
|
255 |
* Set the name of a trace file |
|
256 |
* |
|
257 |
* @file The trace file name or NULL for the default name-<pid> set at |
|
258 |
* config time |
|
200 | 259 |
*/ |
201 |
static void __attribute__((constructor)) st_init(void)
|
|
260 |
bool st_set_trace_file(const char *file)
|
|
202 | 261 |
{ |
203 |
atexit(st_flush_trace_buffer); |
|
262 |
st_set_trace_file_enabled(false); |
|
263 |
|
|
264 |
free(trace_file_name); |
|
265 |
|
|
266 |
if (!file) { |
|
267 |
if (asprintf(&trace_file_name, CONFIG_TRACE_FILE, getpid()) < 0) { |
|
268 |
trace_file_name = NULL; |
|
269 |
return false; |
|
270 |
} |
|
271 |
} else { |
|
272 |
if (asprintf(&trace_file_name, "%s", file) < 0) { |
|
273 |
trace_file_name = NULL; |
|
274 |
return false; |
|
275 |
} |
|
276 |
} |
|
277 |
|
|
278 |
st_set_trace_file_enabled(true); |
|
279 |
return true; |
|
280 |
} |
|
281 |
|
|
282 |
void st_print_trace_file_status(FILE *stream, int (*stream_printf)(FILE *stream, const char *fmt, ...)) |
|
283 |
{ |
|
284 |
stream_printf(stream, "Trace file \"%s\" %s.\n", |
|
285 |
trace_file_name, trace_fp ? "on" : "off"); |
|
204 | 286 |
} |
205 | 287 |
|
206 | 288 |
void st_print_trace(FILE *stream, int (*stream_printf)(FILE *stream, const char *fmt, ...)) |
207 | 289 |
{ |
208 | 290 |
unsigned int i; |
209 | 291 |
|
210 |
for (i = 0; i < trace_idx; i++) { |
|
292 |
for (i = 0; i < TRACE_BUF_LEN; i++) { |
|
293 |
TraceRecord record; |
|
294 |
|
|
295 |
if (!get_trace_record(i, &record)) { |
|
296 |
continue; |
|
297 |
} |
|
211 | 298 |
stream_printf(stream, "Event %" PRIu64 " : %" PRIx64 " %" PRIx64 |
212 | 299 |
" %" PRIx64 " %" PRIx64 " %" PRIx64 " %" PRIx64 "\n", |
213 |
trace_buf[i].event, trace_buf[i].x1, trace_buf[i].x2,
|
|
214 |
trace_buf[i].x3, trace_buf[i].x4, trace_buf[i].x5,
|
|
215 |
trace_buf[i].x6);
|
|
300 |
record.event, record.x1, record.x2,
|
|
301 |
record.x3, record.x4, record.x5,
|
|
302 |
record.x6);
|
|
216 | 303 |
} |
217 | 304 |
} |
218 | 305 |
|
... | ... | |
226 | 313 |
} |
227 | 314 |
} |
228 | 315 |
|
229 |
static TraceEvent* find_trace_event_by_name(const char *tname)
|
|
316 |
bool st_change_trace_event_state(const char *name, bool enabled)
|
|
230 | 317 |
{ |
231 | 318 |
unsigned int i; |
232 | 319 |
|
233 |
if (!tname) { |
|
234 |
return NULL; |
|
235 |
} |
|
236 |
|
|
237 | 320 |
for (i = 0; i < NR_TRACE_EVENTS; i++) { |
238 |
if (!strcmp(trace_list[i].tp_name, tname)) { |
|
239 |
return &trace_list[i]; |
|
321 |
if (!strcmp(trace_list[i].tp_name, name)) { |
|
322 |
trace_list[i].state = enabled; |
|
323 |
return true; |
|
240 | 324 |
} |
241 | 325 |
} |
242 |
return NULL; /* indicates end of list reached without a match */ |
|
326 |
return false; |
|
327 |
} |
|
328 |
|
|
329 |
void st_flush_trace_buffer(void) |
|
330 |
{ |
|
331 |
flush_trace_file(true); |
|
243 | 332 |
} |
244 | 333 |
|
245 |
bool st_change_trace_event_state(const char *tname, bool tstate)
|
|
334 |
void st_init(const char *file)
|
|
246 | 335 |
{ |
247 |
TraceEvent *tp; |
|
336 |
pthread_t thread; |
|
337 |
pthread_attr_t attr; |
|
338 |
sigset_t set, oldset; |
|
339 |
int ret; |
|
340 |
|
|
341 |
pthread_attr_init(&attr); |
|
342 |
pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED); |
|
248 | 343 |
|
249 |
tp = find_trace_event_by_name(tname); |
|
250 |
if (tp) { |
|
251 |
tp->state = tstate; |
|
252 |
return true; |
|
344 |
sigfillset(&set); |
|
345 |
pthread_sigmask(SIG_SETMASK, &set, &oldset); |
|
346 |
ret = pthread_create(&thread, &attr, writeout_thread, NULL); |
|
347 |
pthread_sigmask(SIG_SETMASK, &oldset, NULL); |
|
348 |
|
|
349 |
if (ret != 0) { |
|
350 |
error_report("warning: unable to create trace file thread\n"); |
|
351 |
return; |
|
253 | 352 |
} |
254 |
return false; |
|
353 |
|
|
354 |
atexit(st_flush_trace_buffer); |
|
355 |
st_set_trace_file(file); |
|
255 | 356 |
} |
Also available in: Unified diff