qemu-devel
[Top][All Lists]
Advanced

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

Re: [Qemu-devel] [RFC PATCH v3 2/3] simpletrace-v2: Handle variable numb


From: Harsh Bora
Subject: Re: [Qemu-devel] [RFC PATCH v3 2/3] simpletrace-v2: Handle variable number/size of elements per trace record.
Date: Wed, 18 Jan 2012 14:44:40 +0530
User-agent: Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9.1.10) Gecko/20100621 Fedora/3.0.5-1.fc13 Thunderbird/3.0.5

On 01/10/2012 10:11 PM, Stefan Hajnoczi wrote:
On Tue, Jan 10, 2012 at 10:59 AM, Harsh Prateek Bora
<address@hidden>  wrote:
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<address@hidden>
---
  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); */

This command is only available from the human monitor.  It's not very
useful because it historically hasn't been able to pretty-print events
or show them in the right order (we use a ringbuffer but it prints
them out from index 0).

Therefore, I don't think we're under any obligation to keep this
command around.  No one has complained about it's limitations - I
think this is a sign that no one has used it.  I'd be okay with a
patch that removes it.

  }
  #endif

diff --git a/trace/simple.c b/trace/simple.c
index b639dda..65cafe2 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;

+

Spurious newline.

  /**
  * 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*)&timestamp_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);
+    }

This looks suspicious.  We want to kick the writeout thread when the
buffer reaches the threshold but not repeatedly after that.  Also
because it's a ring buffer idx could "start" above the threshold.

Perhaps something like:
if (idx>  TRACE_BUF_FLUSH_THRESHOLD&&  old_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,

Please don't use .length for the number of bytes dropped because this
makes life harder for parsing scripts like simpletrace.py.  They would
need a special case to check for DROPPED_EVENT_ID and then treat
.length as an argument.  Instead the number of bytes should be an
argument.

Also, by removing the struct literal assignment you lose the automatic
zeroing of fields.  We'll write out junk data - it would be nicer to
clear it.

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

I'm wondering if it's worth using a different approach here.  Writing
out individual records has bothered me.

If we have a second buffer, as big as trace_buf[], then a function can
copy out all records and make them available in trace_buf again:

/**
  * Copy completed trace records out of the ring buffer
  *
  * @idx    offset into trace_buf[]
  * @buf    destination buffer
  * @len    size of destination buffer
  * @ret    the number of bytes consumed
  */
size_t consume_trace_records(unsigned int idx, void *buf, size_t len);

That means consume gobbles up as many records as it can:
  * Until it reaches an invalid record which has not been written yet
  * Until it reaches the end of trace_buf[], the caller can call again
with idx wrapped to 0

After copying into buf[] it clears the valid bit in trace_buf[].

Then the loop which calls consume_trace_records() does a single
fwrite(3) and increments idx/writeout_idx.

The advantage to this is that we write many records in one go and I
think it splits up the writeout steps a little nicer than what we've
previously done.


I think this optimization can be introduced as a separate patch later.
Let me know if you think otherwise.


         fflush(trace_fp);
@@ -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,

Hmm...this is kind of ugly (see comment about using .length above) but
in this case most parsers will have a special-case anyway to check the
magic number.  We need to use the .length field because historically
that's where the version is located.


So, lets keep the version here only, right ?

- Harsh

+/* Interfaces for simpletrace v2 */

Please drop this comment.  All trace/simple.[ch] code is for v2, this
makes it seems like we support both versions at the same time.

+
+/** 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;

Does this need to be visible?  I think it can live in trace/simple.c

+
+#define ST_V2_REC_HDR_LEN 24

Does not need to be visible.  Also why calculate manually, instead of
a macro I would use sizeof(TraceRecord) (the array without elements is
not counted by sizeof).

+
+enum {
+    TRACE_BUF_LEN = 4096 * 64,
+    TRACE_BUF_FLUSH_THRESHOLD = TRACE_BUF_LEN / 4,
+};

Does not need to be visible.

+
+extern uint8_t trace_buf[TRACE_BUF_LEN];

Does not need to be visible.





reply via email to

[Prev in Thread] Current Thread [Next in Thread]