From patchwork Mon Jan 2 06:50:21 2012 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Harsh Prateek Bora X-Patchwork-Id: 133801 Return-Path: X-Original-To: incoming@patchwork.ozlabs.org Delivered-To: patchwork-incoming@bilbo.ozlabs.org Received: from lists.gnu.org (lists.gnu.org [140.186.70.17]) (using TLSv1 with cipher AES256-SHA (256/256 bits)) (Client did not present a certificate) by ozlabs.org (Postfix) with ESMTPS id B5607B6FA0 for ; Mon, 2 Jan 2012 18:11:28 +1100 (EST) Received: from localhost ([::1]:35626 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1RhbkR-0004hR-5a for incoming@patchwork.ozlabs.org; Mon, 02 Jan 2012 01:51:55 -0500 Received: from eggs.gnu.org ([140.186.70.92]:45874) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1Rhbjj-0002ey-Fm for qemu-devel@nongnu.org; Mon, 02 Jan 2012 01:51:13 -0500 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1Rhbjh-00008t-FZ for qemu-devel@nongnu.org; Mon, 02 Jan 2012 01:51:11 -0500 Received: from e23smtp06.au.ibm.com ([202.81.31.148]:46374) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1Rhbjg-000085-Au for qemu-devel@nongnu.org; Mon, 02 Jan 2012 01:51:09 -0500 Received: from /spool/local by e23smtp06.au.ibm.com with IBM ESMTP SMTP Gateway: Authorized Use Only! Violators will be prosecuted for from ; Mon, 2 Jan 2012 06:48:22 +1000 Received: from d23relay05.au.ibm.com ([202.81.31.247]) by e23smtp06.au.ibm.com ([202.81.31.212]) with IBM ESMTP SMTP Gateway: Authorized Use Only! Violators will be prosecuted; Mon, 2 Jan 2012 06:47:59 +1000 Received: from d23av01.au.ibm.com (d23av01.au.ibm.com [9.190.234.96]) by d23relay05.au.ibm.com (8.13.8/8.13.8/NCO v10.0) with ESMTP id q026kT483678364 for ; Mon, 2 Jan 2012 17:46:29 +1100 Received: from d23av01.au.ibm.com (loopback [127.0.0.1]) by d23av01.au.ibm.com (8.14.4/8.13.1/NCO v10.0 AVout) with ESMTP id q026ofl6027647 for ; Mon, 2 Jan 2012 17:50:41 +1100 Received: from harshbora.in.ibm.com ([9.124.35.40]) by d23av01.au.ibm.com (8.14.4/8.13.1/NCO v10.0 AVin) with ESMTP id q026oQwI027022; Mon, 2 Jan 2012 17:50:40 +1100 From: Harsh Prateek Bora To: qemu-devel@nongnu.org Date: Mon, 2 Jan 2012 12:20:21 +0530 Message-Id: <1325487023-10613-4-git-send-email-harsh@linux.vnet.ibm.com> X-Mailer: git-send-email 1.7.1.1 In-Reply-To: <1325487023-10613-1-git-send-email-harsh@linux.vnet.ibm.com> References: <1325487023-10613-1-git-send-email-harsh@linux.vnet.ibm.com> x-cbid: 12010120-7014-0000-0000-0000005B9353 X-detected-operating-system: by eggs.gnu.org: Genre and OS details not recognized. X-Received-From: 202.81.31.148 Cc: Harsh Prateek Bora , stefanha@linux.vnet.ibm.com, aneesh.kumar@linux.vnet.ibm.com Subject: [Qemu-devel] [RFC PATCH 3/4] simpletrace-v2: Handle variable number/size of elements per trace record. X-BeenThere: qemu-devel@nongnu.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: qemu-devel-bounces+incoming=patchwork.ozlabs.org@nongnu.org Sender: qemu-devel-bounces+incoming=patchwork.ozlabs.org@nongnu.org Advantages over existing simpletrace backend: - More than 6 elements (vitually unlimited) arguments can be traced. - This allows to trace strings (variable size element) as well. Signed-off-by: Harsh Prateek Bora --- monitor.c | 2 +- trace/simple.c | 178 ++++++++++++++++++++------------------------------------ trace/simple.h | 31 ++++++++-- 3 files changed, 88 insertions(+), 123 deletions(-) diff --git a/monitor.c b/monitor.c index ffda0fe..b6f85d1 100644 --- a/monitor.c +++ b/monitor.c @@ -945,7 +945,7 @@ static void do_info_cpu_stats(Monitor *mon) #if defined(CONFIG_TRACE_SIMPLE) static void do_info_trace(Monitor *mon) { - st_print_trace((FILE *)mon, &monitor_fprintf); + /* FIXME: st_print_trace((FILE *)mon, &monitor_fprintf); */ } #endif diff --git a/trace/simple.c b/trace/simple.c index b639dda..f7e7967 100644 --- a/trace/simple.c +++ b/trace/simple.c @@ -27,7 +27,7 @@ #define HEADER_MAGIC 0xf2b177cb0aa429b4ULL /** Trace file version number, bump if format changes */ -#define HEADER_VERSION 0 +#define HEADER_VERSION 2 /** Records were dropped event ID */ #define DROPPED_EVENT_ID (~(uint64_t)0 - 1) @@ -35,23 +35,6 @@ /** Trace record is valid */ #define TRACE_RECORD_VALID ((uint64_t)1 << 63) -/** Trace buffer entry */ -typedef struct { - uint64_t event; - uint64_t timestamp_ns; - uint64_t x1; - uint64_t x2; - uint64_t x3; - uint64_t x4; - uint64_t x5; - uint64_t x6; -} TraceRecord; - -enum { - TRACE_BUF_LEN = 4096, - TRACE_BUF_FLUSH_THRESHOLD = TRACE_BUF_LEN / 4, -}; - /* * Trace records are written out by a dedicated thread. The thread waits for * records to become available, writes them out, and then waits again. @@ -62,11 +45,12 @@ static GCond *trace_empty_cond; static bool trace_available; static bool trace_writeout_enabled; -static TraceRecord trace_buf[TRACE_BUF_LEN]; +uint8_t trace_buf[TRACE_BUF_LEN]; static unsigned int trace_idx; static FILE *trace_fp; static char *trace_file_name = NULL; + /** * Read a trace record from the trace buffer * @@ -75,16 +59,19 @@ static char *trace_file_name = NULL; * * Returns false if the record is not valid. */ -static bool get_trace_record(unsigned int idx, TraceRecord *record) +static bool get_trace_record(unsigned int idx, TraceRecord **recordptr) { - if (!(trace_buf[idx].event & TRACE_RECORD_VALID)) { + TraceRecord *record = (TraceRecord *) &trace_buf[idx]; + if (!(record->event & TRACE_RECORD_VALID)) { return false; } __sync_synchronize(); /* read memory barrier before accessing record */ - *record = trace_buf[idx]; - record->event &= ~TRACE_RECORD_VALID; + *recordptr = g_malloc(record->length); + /* make a copy of record to avoid being overwritten */ + memcpy(*recordptr, record, record->length); + (*recordptr)->event &= ~TRACE_RECORD_VALID; return true; } @@ -106,6 +93,47 @@ static void flush_trace_file(bool wait) g_static_mutex_unlock(&trace_lock); } +unsigned int trace_alloc_record(TraceEventID event, uint32_t datasize) +{ + unsigned int idx, rec_off; + uint32_t rec_len = ST_V2_REC_HDR_LEN + datasize; + uint64_t timestamp_ns = get_clock(); + + idx = g_atomic_int_exchange_and_add((gint *)&trace_idx, rec_len) % TRACE_BUF_LEN; + rec_off = idx; + write_to_buffer(rec_off, (uint8_t*)&event, sizeof(event)); + rec_off += sizeof(event); + write_to_buffer(rec_off, (uint8_t*)×tamp_ns, sizeof(timestamp_ns)); + rec_off += sizeof(timestamp_ns); + write_to_buffer(rec_off, (uint8_t*)&rec_len, sizeof(rec_len)); + rec_off += sizeof(rec_len); + return idx; +} + +void write_to_buffer(unsigned int idx, uint8_t *dataptr, uint32_t size) +{ + uint32_t x = 0; + while (x < size) + { + if (idx >= TRACE_BUF_LEN) { + idx = idx % TRACE_BUF_LEN; + } + trace_buf[idx++] = dataptr[x++]; + } +} + +void trace_mark_record_complete(unsigned int idx) +{ + TraceRecord *record = (TraceRecord*) &trace_buf[idx];; + + __sync_synchronize(); /* write barrier before marking as valid */ + record->event |= TRACE_RECORD_VALID; + + if (idx > TRACE_BUF_FLUSH_THRESHOLD) { + flush_trace_file(false); + } +} + static void wait_for_trace_records_available(void) { g_static_mutex_lock(&trace_lock); @@ -120,7 +148,7 @@ static void wait_for_trace_records_available(void) static gpointer writeout_thread(gpointer opaque) { - TraceRecord record; + TraceRecord record, *recordptr; unsigned int writeout_idx = 0; unsigned int num_available, idx; size_t unused __attribute__ ((unused)); @@ -130,19 +158,20 @@ static gpointer writeout_thread(gpointer opaque) num_available = trace_idx - writeout_idx; if (num_available > TRACE_BUF_LEN) { - record = (TraceRecord){ - .event = DROPPED_EVENT_ID, - .x1 = num_available, - }; - unused = fwrite(&record, sizeof(record), 1, trace_fp); + record.event = DROPPED_EVENT_ID, + record.length = num_available, + unused = fwrite(&record, ST_V2_REC_HDR_LEN, 1, trace_fp); writeout_idx += num_available; } idx = writeout_idx % TRACE_BUF_LEN; - while (get_trace_record(idx, &record)) { - trace_buf[idx].event = 0; /* clear valid bit */ - unused = fwrite(&record, sizeof(record), 1, trace_fp); - idx = ++writeout_idx % TRACE_BUF_LEN; + while (get_trace_record(idx, &recordptr)) { + unused = fwrite(recordptr, recordptr->length, 1, trace_fp); + writeout_idx += recordptr->length; + g_free(recordptr); + recordptr = (TraceRecord *) &trace_buf[idx]; + recordptr->event = 0; + idx = writeout_idx % TRACE_BUF_LEN; } fflush(trace_fp); @@ -150,71 +179,7 @@ static gpointer writeout_thread(gpointer opaque) return NULL; } -static void trace(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, - uint64_t x4, uint64_t x5, uint64_t x6) -{ - unsigned int idx; - uint64_t timestamp; - - if (!trace_list[event].state) { - return; - } - - timestamp = get_clock(); - - idx = g_atomic_int_exchange_and_add((gint *)&trace_idx, 1) % TRACE_BUF_LEN; - trace_buf[idx] = (TraceRecord){ - .event = event, - .timestamp_ns = timestamp, - .x1 = x1, - .x2 = x2, - .x3 = x3, - .x4 = x4, - .x5 = x5, - .x6 = x6, - }; - __sync_synchronize(); /* write barrier before marking as valid */ - trace_buf[idx].event |= TRACE_RECORD_VALID; - - if ((idx + 1) % TRACE_BUF_FLUSH_THRESHOLD == 0) { - flush_trace_file(false); - } -} - -void trace0(TraceEventID event) -{ - trace(event, 0, 0, 0, 0, 0, 0); -} - -void trace1(TraceEventID event, uint64_t x1) -{ - trace(event, x1, 0, 0, 0, 0, 0); -} - -void trace2(TraceEventID event, uint64_t x1, uint64_t x2) -{ - trace(event, x1, x2, 0, 0, 0, 0); -} -void trace3(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3) -{ - trace(event, x1, x2, x3, 0, 0, 0); -} - -void trace4(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, uint64_t x4) -{ - trace(event, x1, x2, x3, x4, 0, 0); -} - -void trace5(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, uint64_t x4, uint64_t x5) -{ - trace(event, x1, x2, x3, x4, x5, 0); -} - -void trace6(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, uint64_t x4, uint64_t x5, uint64_t x6) -{ - trace(event, x1, x2, x3, x4, x5, x6); -} void st_set_trace_file_enabled(bool enable) { @@ -231,7 +196,7 @@ void st_set_trace_file_enabled(bool enable) static const TraceRecord header = { .event = HEADER_EVENT_ID, .timestamp_ns = HEADER_MAGIC, - .x1 = HEADER_VERSION, + .length = HEADER_VERSION, }; trace_fp = fopen(trace_file_name, "wb"); @@ -288,23 +253,6 @@ void st_print_trace_file_status(FILE *stream, int (*stream_printf)(FILE *stream, trace_file_name, trace_fp ? "on" : "off"); } -void st_print_trace(FILE *stream, int (*stream_printf)(FILE *stream, const char *fmt, ...)) -{ - unsigned int i; - - for (i = 0; i < TRACE_BUF_LEN; i++) { - TraceRecord record; - - if (!get_trace_record(i, &record)) { - continue; - } - stream_printf(stream, "Event %" PRIu64 " : %" PRIx64 " %" PRIx64 - " %" PRIx64 " %" PRIx64 " %" PRIx64 " %" PRIx64 "\n", - record.event, record.x1, record.x2, - record.x3, record.x4, record.x5, - record.x6); - } -} void st_flush_trace_buffer(void) { diff --git a/trace/simple.h b/trace/simple.h index 466e75b..671cbeb 100644 --- a/trace/simple.h +++ b/trace/simple.h @@ -22,17 +22,34 @@ typedef struct { bool state; } TraceEvent; -void trace0(TraceEventID event); -void trace1(TraceEventID event, uint64_t x1); -void trace2(TraceEventID event, uint64_t x1, uint64_t x2); -void trace3(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3); -void trace4(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, uint64_t x4); -void trace5(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, uint64_t x4, uint64_t x5); -void trace6(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, uint64_t x4, uint64_t x5, uint64_t x6); void st_print_trace(FILE *stream, fprintf_function stream_printf); void st_print_trace_file_status(FILE *stream, fprintf_function stream_printf); void st_set_trace_file_enabled(bool enable); bool st_set_trace_file(const char *file); void st_flush_trace_buffer(void); +/* Interfaces for simpletrace v2 */ + +/** Trace buffer entry */ +typedef struct { + uint64_t event; /* TraceEventID */ + uint64_t timestamp_ns; + uint32_t length; /* in bytes */ + uint32_t reserved; /* unused */ + uint8_t arguments[]; /* arguments position affects ST_V2_REC_HDR_LEN */ +} TraceRecord; + +#define ST_V2_REC_HDR_LEN 24 + +enum { + TRACE_BUF_LEN = 4096 * 64, + TRACE_BUF_FLUSH_THRESHOLD = TRACE_BUF_LEN / 4, +}; + +extern uint8_t trace_buf[TRACE_BUF_LEN]; + +unsigned int trace_alloc_record(TraceEventID event, uint32_t datasize); +void write_to_buffer(unsigned int idx, uint8_t *dataptr, uint32_t size); +void trace_mark_record_complete(unsigned int idx); + #endif /* TRACE_SIMPLE_H */