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