File:  [Qemu by Fabrice Bellard] / qemu / simpletrace.c
Revision 1.1.1.2 (vendor branch): download - view: text, annotated - select for diffs
Tue Apr 24 18:56:28 2018 UTC (19 months, 2 weeks ago) by root
Branches: qemu, MAIN
CVS tags: qemu1000, qemu0151, HEAD
qemu 0.15.1

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

unix.superglobalmegacorp.com