qemu-devel
[Top][All Lists]
Advanced

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

Re: [Qemu-devel] [PATCH v5 2/3] Simpletrace v2: Support multiple argumen


From: Harsh Bora
Subject: Re: [Qemu-devel] [PATCH v5 2/3] Simpletrace v2: Support multiple arguments, strings.
Date: Thu, 14 Jun 2012 19:21:35 +0530
User-agent: Mozilla/5.0 (X11; Linux x86_64; rv:12.0) Gecko/20120430 Thunderbird/12.0.1

Hi Stefan,
Please see comment below:

On 06/14/2012 07:02 PM, Harsh Prateek Bora wrote:

[...]

-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)) {
+    uint8_t rec_hdr[sizeof(TraceRecord)];
+    uint64_t event_flag = 0;
+    TraceRecord *record = (TraceRecord *) rec_hdr;
+    /* read the event flag to see if its a valid record */
+    read_from_buffer(idx, rec_hdr, sizeof(event_flag));
+
+    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;
-    return true;
+    /* read the record header to know record length */
+    read_from_buffer(idx, rec_hdr, sizeof(TraceRecord));
+    *recordptr = g_malloc(record->length);
+    /* make a copy of record to avoid being overwritten */
+    read_from_buffer(idx, (uint8_t *)*recordptr, record->length);
+    __sync_synchronize(); /* memory barrier before clearing valid flag */
+    (*recordptr)->event&= ~TRACE_RECORD_VALID;
+    /* reset record event validity flag on global trace buffer */
+    write_to_buffer(idx,&event_flag, sizeof(event_flag));
+    if ((*recordptr)->event<  NR_TRACE_EVENTS) {
+        return true;
+    } else {
+        /* XXX: Ideally this should not happen, but its possible !
+         * See comments in trace_record_start for more details.
+         * We dont know where to start next and therefore resetting
+         * writeout_idx to trace_idx. Also, as we dont know how many
+         * events dropped in between, at least increment the count by one.
+         */
+        g_atomic_int_inc((gint *)&dropped_events);
+        g_free(*recordptr);
+        writeout_idx = trace_idx;
+        return false;
+    }
  }


[...]


-void trace1(TraceEventID event, uint64_t x1)
+int trace_record_start(TraceBufferRecord *rec, TraceEventID event, size_t 
datasize)
  {
-    trace(event, x1, 0, 0, 0, 0, 0);
-}
+    unsigned int idx, rec_off, old_idx, new_idx;
+    uint32_t rec_len = sizeof(TraceRecord) + datasize;
+    uint64_t timestamp_ns = get_clock();
+
+    while (1) {
+        old_idx = trace_idx;
+        smp_rmb();
+        new_idx = old_idx + rec_len;
+
+        if (new_idx - writeout_idx>  TRACE_BUF_LEN) {
+            /* Trace Buffer Full, Event dropped ! */
+            g_atomic_int_inc((gint *)&dropped_events);
+            return -ENOSPC;
+        }

-void trace2(TraceEventID event, uint64_t x1, uint64_t x2)
-{
-    trace(event, x1, x2, 0, 0, 0, 0);
-}
+        /* XXX: If threads race here, take care in get_trace_record */


I see that this comment is invalid, but there is something corrupting the trace buffer. If I remove the check for event_id < NR_TRACE_EVENTS in get_trace_record, it is finding corrupted records after about 10K records being traced, strangely with valid flag set set.
I do not see any obvious reason for this, do you ?

regards,
Harsh


-void trace3(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3)
-{
-    trace(event, x1, x2, x3, 0, 0, 0);
+        if (g_atomic_int_compare_and_exchange((gint *)&trace_idx,
+                                              old_idx, new_idx)) {
+            break;
+        }
+    }
+
+    idx = old_idx % TRACE_BUF_LEN;
+    /*  To check later if threshold crossed */
+    rec->next_tbuf_idx = new_idx % TRACE_BUF_LEN;
+
+    rec_off = idx;
+    rec_off = write_to_buffer(rec_off, (uint8_t*)&event, sizeof(event));
+    rec_off = write_to_buffer(rec_off, (uint8_t*)&timestamp_ns, 
sizeof(timestamp_ns));
+    rec_off = write_to_buffer(rec_off, (uint8_t*)&rec_len, sizeof(rec_len));
+
+    rec->tbuf_idx = idx;
+    rec->rec_off  = (idx + sizeof(TraceRecord)) % TRACE_BUF_LEN;
+    return 0;
  }

-void trace4(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, 
uint64_t x4)
+static void read_from_buffer(unsigned int idx, void *dataptr, size_t size)
  {
-    trace(event, x1, x2, x3, x4, 0, 0);
+    uint8_t *data_ptr = dataptr;
+    uint32_t x = 0;
+    while (x<  size) {
+        if (idx>= TRACE_BUF_LEN) {
+            idx = idx % TRACE_BUF_LEN;
+        }
+        data_ptr[x++] = trace_buf[idx++];
+    }
  }

-void trace5(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, 
uint64_t x4, uint64_t x5)
+static unsigned int write_to_buffer(unsigned int idx, void *dataptr, size_t 
size)
  {
-    trace(event, x1, x2, x3, x4, x5, 0);
+    uint8_t *data_ptr = dataptr;
+    uint32_t x = 0;
+    while (x<  size) {
+        if (idx>= TRACE_BUF_LEN) {
+            idx = idx % TRACE_BUF_LEN;
+        }
+        trace_buf[idx++] = data_ptr[x++];
+    }
+    return idx; /* most callers wants to know where to write next */
  }

-void trace6(TraceEventID event, uint64_t x1, uint64_t x2, uint64_t x3, 
uint64_t x4, uint64_t x5, uint64_t x6)
+void trace_record_finish(TraceBufferRecord *rec)
  {
-    trace(event, x1, x2, x3, x4, x5, x6);
+    uint8_t temp_rec[sizeof(TraceRecord)];
+    TraceRecord *record = (TraceRecord *) temp_rec;
+    read_from_buffer(rec->tbuf_idx, temp_rec, sizeof(TraceRecord));
+    __sync_synchronize(); /* write barrier before marking as valid */
+    record->event |= TRACE_RECORD_VALID;
+    write_to_buffer(rec->tbuf_idx, temp_rec, sizeof(TraceRecord));
+
+    if ((trace_idx>  writeout_idx)&&
+        (trace_idx - writeout_idx)>  TRACE_BUF_FLUSH_THRESHOLD) {
+        flush_trace_file(false);
+    } else if ((writeout_idx>  trace_idx)&&
+              (trace_idx>  TRACE_BUF_FLUSH_THRESHOLD)) {
+        /* if trace_idx rollover before writeout_idx */
+        flush_trace_file(false);
+    }
  }

  void st_set_trace_file_enabled(bool enable)
@@ -231,10 +304,11 @@ void st_set_trace_file_enabled(bool enable)
      flush_trace_file(true);

      if (enable) {
-        static const TraceRecord header = {
-            .event = HEADER_EVENT_ID,
-            .timestamp_ns = HEADER_MAGIC,
-            .x1 = HEADER_VERSION,
+        static const TraceRecordHeader header = {
+            .header_event_id = HEADER_EVENT_ID,
+            .header_magic = HEADER_MAGIC,
+            /* Older log readers will check for version at next location */
+            .header_version = HEADER_VERSION,
          };

          trace_fp = fopen(trace_file_name, "wb");
diff --git a/trace/simple.h b/trace/simple.h
index 6b5358c..6755e99 100644
--- a/trace/simple.h
+++ b/trace/simple.h
@@ -22,16 +22,39 @@ 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_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);

+typedef struct {
+    unsigned int tbuf_idx;
+    unsigned int next_tbuf_idx;
+    unsigned int rec_off;
+} TraceBufferRecord;
+
+/**
+ * Initialize a trace record and claim space for it in the buffer
+ *
+ * @arglen  number of bytes required for arguments
+ */
+int trace_record_start(TraceBufferRecord *rec, TraceEventID id, size_t arglen);
+
+/**
+ * Append a 64-bit argument to a trace record
+ */
+void trace_record_write_u64(TraceBufferRecord *rec, uint64_t val);
+
+/**
+ * Append a string argument to a trace record
+ */
+void trace_record_write_str(TraceBufferRecord *rec, const char *s);
+
+/**
+ * Mark a trace record completed
+ *
+ * Don't append any more arguments to the trace record after calling this.
+ */
+void trace_record_finish(TraceBufferRecord *rec);
+
  #endif /* TRACE_SIMPLE_H */




reply via email to

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