Implement TimeTrace::recordIfNotDup that collapses duplicate messages.

Similar to RAMCLOUD_CLOG but more limited:
 * Only support messages with no printf format specifiers.
 * Only collapse identical messages that appear consecutively in the buffer.

Author: yilongli

cwrapper/timetrace_wrapper.cc

@@ -65,6 +65,17 @@ timetrace_record_ts(uint64_t timestamp, const char* format, uint32_t arg0,
     TimeTrace::record(timestamp, format, arg0, arg1, arg2, arg3);
 }
 
+/**
+ * This function is the wrapper for TimeTrace::recordIfNotDup.
+ *
+ * Since we cannot separate definition and declaration of inline function, so
+ * this function cannot be inline function.
+ */
+void
+timetrace_record_if_not_dup(const char* message) {
+    TimeTrace::recordIfNotDup(message);
+}
+
 /**
  * This function is used to set TimeTrace::keepOldEvents
  */

cwrapper/timetrace_wrapper.h

@@ -44,6 +44,12 @@ void timetrace_record();
  *                          uint32_t arg3);
  */
 void timetrace_record_ts();
+/**
+ * The real signature of this function is the following. The message string is
+ * mandatory.
+ * void timetrace_record_if_not_dup(const char* message);
+ */
+void timetrace_record_if_not_dup();
 void timetrace_set_keepoldevents(bool keep);
 
 #ifdef __cplusplus

src/TimeTrace.cc

@@ -145,6 +145,39 @@ TimeTrace::Buffer::record(uint64_t timestamp, const char* format, uint32_t arg0,
     event->arg3 = arg3;
 }
 
+/**
+ * Similar to TimeTrace::Buffer::record but collapse consecutive messages that
+ * are identical.
+ *
+ * \param timestamp
+ *      Identifies the time at which the event occurred.
+ * \param message
+ *      A message string with no printf format specifiers.
+ */
+void
+TimeTrace::Buffer::recordIfNotDup(uint64_t timestamp, const char* message) {
+    if (activeReaders > 0) {
+        return;
+    }
+
+    Event* lastEvent = &events[nextIndex > 0 ? nextIndex - 1 : BUFFER_SIZE - 1];
+    if (lastEvent->format == message) {
+        lastEvent->timestamp = timestamp;
+        lastEvent->arg0++;
+        return;
+    }
+
+    Event* event = &events[nextIndex];
+    nextIndex = (nextIndex + 1) & BUFFER_MASK;
+
+    event->timestamp = timestamp;
+    event->format = message;
+    event->arg0 = 1;
+    event->arg1 = ~0u;
+    event->arg2 = ~0u;
+    event->arg3 = ~0u;
+}
+
 /**
  * Return a string containing a printout of the records in the buffer.
  */
@@ -319,6 +352,8 @@ TimeTrace::printInternal(std::vector<TimeTrace::Buffer*>* buffers, string* s) {
             (current[currentBuffer] + 1) & Buffer::BUFFER_MASK;
 
         char message[1000];
+        const char* repeatedTimes = " (repeated %u times)";
+#define IS_REPEATED_EVENT(x) ((x->arg0 > 1) && (x->arg1 == ~0u))
         double ns = Cycles::toSeconds(event->timestamp - startTime) * 1e09;
         if (s != NULL) {
             if (s->length() != 0) {
@@ -333,6 +368,11 @@ TimeTrace::printInternal(std::vector<TimeTrace::Buffer*>* buffers, string* s) {
                      event->arg1, event->arg2, event->arg3);
 #pragma GCC diagnostic pop
             s->append(message);
+            if (IS_REPEATED_EVENT(event)) {
+                char m[100];
+                snprintf(m, sizeof(m), repeatedTimes, event->arg0);
+                s->append(m);
+            }
         } else {
 #pragma GCC diagnostic push
 #pragma GCC diagnostic ignored "-Wformat-nonliteral"
@@ -341,6 +381,9 @@ TimeTrace::printInternal(std::vector<TimeTrace::Buffer*>* buffers, string* s) {
 #pragma GCC diagnostic pop
             fprintf(output, "%8.1f ns (+%6.1f ns): %s", ns, ns - prevTime,
                     message);
+            if (IS_REPEATED_EVENT(event)) {
+                fprintf(output, repeatedTimes, event->arg0);
+            }
             fputc('\n', output);
         }
         prevTime = ns;

src/TimeTrace.h

@@ -89,6 +89,21 @@ class TimeTrace {
                               uint32_t arg3 = 0) {
         record(Cycles::rdtsc(), format, arg0, arg1, arg2, arg3);
     }
+
+    /**
+     * Similar to TimeTrace::record but collapse consecutive messages that are
+     * identical. To simplify the detection of duplicate messages, this function
+     * currently doesn't support messages with printf format specifiers.
+     *
+     * \param message
+     *      A message string with no printf format specifiers.
+     */
+    static inline void recordIfNotDup(const char* message) {
+        if (threadBuffer == NULL) {
+            createThreadBuffer();
+        }
+        threadBuffer->recordIfNotDup(Cycles::rdtsc(), message);
+    }
     static void reset();
     /**
      * When this bool is set, the print method in TimeTrace will use the
@@ -153,6 +168,7 @@ class TimeTrace {
                     uint32_t arg2 = 0, uint32_t arg3 = 0) {
             record(Cycles::rdtsc(), format, arg0, arg1, arg2, arg3);
         }
+        void recordIfNotDup(uint64_t timestamp, const char* format);
         void reset();
 
       protected: