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 |
}
|