Involve more log compression techniques.

Code addresses are now written as an offset from the previous address for ticks, code move and delete events. Employed backreference and RLE compression for code move and delete events. This gives additional 30% log size reduction for benchmarks run w/o snapshot.

Overall compression results (compared with the revision of V8 having no compression):
 - V8: 70% size reduction for benchmarks run w/o snapshot (for reference, gzip gives 87%)
 - Chromium: 65% size reduction for public html version of benchmarks (v4) (for reference, gzip gives 90%)

The one obvious opportunity for improving compression results in Chromium is to compress URLs of scripts.

Review URL: http://codereview.chromium.org/125114


git-svn-id: http://v8.googlecode.com/svn/branches/bleeding_edge@2162 ce2b1a6d-e550-0410-aec6-3dcde31c8c00

src/log-utils.cc

@@ -127,18 +127,11 @@ LogDynamicBuffer* Log::output_buffer_ = NULL;
 const char* Log::kDynamicBufferSeal = "profiler,\"pause\"\n";
 Mutex* Log::mutex_ = NULL;
 char* Log::message_buffer_ = NULL;
-LogRecordCompressor* Log::record_compressor_ = NULL;
-// Must be the same as compressed tick event name from Logger.
-const char* Log::kCompressedTickEventName = "t,";
 
 
 void Log::Init() {
   mutex_ = OS::CreateMutex();
   message_buffer_ = NewArray<char>(kMessageBufferSize);
-  if (FLAG_compress_log) {
-    record_compressor_ = new LogRecordCompressor(
-        kRecordCompressorWindow, strlen(kCompressedTickEventName));
-  }
 }
 
 
@@ -180,9 +173,6 @@ void Log::Close() {
   }
   Write = NULL;
 
-  delete record_compressor_;
-  record_compressor_ = NULL;
-
   DeleteArray(message_buffer_);
   message_buffer_ = NULL;
 
@@ -263,6 +253,27 @@ void LogMessageBuilder::Append(String* str) {
 }
 
 
+void LogMessageBuilder::AppendAddress(Address addr) {
+  static Address last_address_ = NULL;
+  AppendAddress(addr, last_address_);
+  last_address_ = addr;
+}
+
+
+void LogMessageBuilder::AppendAddress(Address addr, Address bias) {
+  if (!FLAG_compress_log || bias == NULL) {
+    Append("0x%" V8PRIxPTR, addr);
+  } else {
+    intptr_t delta = addr - bias;
+    // To avoid printing negative offsets in an unsigned form,
+    // we are printing an absolute value with a sign.
+    const char sign = delta >= 0 ? '+' : '-';
+    if (sign == '-') { delta = -delta; }
+    Append("%c%" V8PRIxPTR, sign, delta);
+  }
+}
+
+
 void LogMessageBuilder::AppendDetailed(String* str, bool show_impl_info) {
   AssertNoAllocation no_heap_allocation;  // Ensure string stay valid.
   int len = str->length();
@@ -293,24 +304,19 @@ void LogMessageBuilder::AppendDetailed(String* str, bool show_impl_info) {
 }
 
 
-bool LogMessageBuilder::StoreInCompressor() {
-  if (!FLAG_compress_log) return true;
-  ASSERT(Log::record_compressor_ != NULL);
-  return Log::record_compressor_->Store(
-      Vector<const char>(Log::message_buffer_, pos_));
+bool LogMessageBuilder::StoreInCompressor(LogRecordCompressor* compressor) {
+  return compressor->Store(Vector<const char>(Log::message_buffer_, pos_));
 }
 
 
-bool LogMessageBuilder::RetrieveCompressedPrevious(const char* prefix) {
-  if (!FLAG_compress_log) return true;
-  ASSERT(Log::record_compressor_ != NULL);
+bool LogMessageBuilder::RetrieveCompressedPrevious(
+    LogRecordCompressor* compressor, const char* prefix) {
   pos_ = 0;
   if (prefix[0] != '\0') Append(prefix);
   Vector<char> prev_record(Log::message_buffer_ + pos_,
                            Log::kMessageBufferSize - pos_);
-  const bool has_previous =
-      Log::record_compressor_->RetrievePreviousCompressed(&prev_record);
-  if (!has_previous) return false;
+  const bool has_prev = compressor->RetrievePreviousCompressed(&prev_record);
+  if (!has_prev) return false;
   pos_ += prev_record.length();
   return true;
 }
@@ -334,6 +340,10 @@ void LogMessageBuilder::WriteCStringToLogFile(const char* str) {
 }
 
 
+// Formatting string for back references to the whole line. E.g. "#2" means
+// "the second line above".
+const char* LogRecordCompressor::kLineBackwardReferenceFormat = "#%d";
+
 // Formatting string for back references. E.g. "#2:10" means
 // "the second line above, start from char 10 (0-based)".
 const char* LogRecordCompressor::kBackwardReferenceFormat = "#%d:%d";
@@ -346,6 +356,34 @@ LogRecordCompressor::~LogRecordCompressor() {
 }
 
 
+static int GetNumberLength(int number) {
+  ASSERT(number >= 0);
+  ASSERT(number < 10000);
+  if (number < 10) return 1;
+  if (number < 100) return 2;
+  if (number < 1000) return 3;
+  return 4;
+}
+
+
+int LogRecordCompressor::GetBackwardReferenceSize(int distance, int pos) {
+  // See kLineBackwardReferenceFormat and kBackwardReferenceFormat.
+  return pos == 0 ? GetNumberLength(distance) + 1
+      : GetNumberLength(distance) + GetNumberLength(pos) + 2;
+}
+
+
+void LogRecordCompressor::PrintBackwardReference(Vector<char> dest,
+                                                 int distance,
+                                                 int pos) {
+  if (pos == 0) {
+    OS::SNPrintF(dest, kLineBackwardReferenceFormat, distance);
+  } else {
+    OS::SNPrintF(dest, kBackwardReferenceFormat, distance, pos);
+  }
+}
+
+
 bool LogRecordCompressor::Store(const Vector<const char>& record) {
   // Check if the record is the same as the last stored one.
   if (curr_ != -1) {
@@ -379,9 +417,10 @@ bool LogRecordCompressor::RetrievePreviousCompressed(
     intptr_t truncated_len;
     int distance;
     int copy_from_pos;
-  } best = {-1, 0, 0};
+    int backref_size;
+  } best = {-1, 0, 0, 0};
   Vector<const char>& prev = buffer_[prev_];
-  const char* const prev_start = prev.start() + start_pos_;
+  const char* const prev_start = prev.start();
   const char* const prev_end = prev.start() + prev.length();
   do {
     // We're moving backwards until we reach the current record.
@@ -402,13 +441,19 @@ bool LogRecordCompressor::RetrievePreviousCompressed(
       --data_ptr;
     }
     const intptr_t truncated_len = prev_end - prev_ptr;
-    if (truncated_len < kUncompressibleBound) continue;
+    const int copy_from_pos = data_ptr - data.start();
+    // Check if the length of compressed tail is enough.
+    if (truncated_len <= kMaxBackwardReferenceSize
+        && truncated_len <= GetBackwardReferenceSize(distance, copy_from_pos)) {
+      continue;
+    }
 
     // Record compression results.
     if (truncated_len > best.truncated_len) {
       best.truncated_len = truncated_len;
       best.distance = distance;
-      best.copy_from_pos = data_ptr - data.start();
+      best.copy_from_pos = copy_from_pos;
+      best.backref_size = GetBackwardReferenceSize(distance, copy_from_pos);
     }
   } while (true);
 
@@ -420,14 +465,15 @@ bool LogRecordCompressor::RetrievePreviousCompressed(
   } else {
     // Copy the uncompressible part unchanged.
     const intptr_t unchanged_len = prev.length() - best.truncated_len;
-    ASSERT(prev_record->length() >= unchanged_len + kUncompressibleBound);
+    // + 1 for '\0'.
+    ASSERT(prev_record->length() >= unchanged_len + best.backref_size + 1);
     memcpy(prev_record->start(), prev.start(), unchanged_len);
     // Append the backward reference.
-    Vector<char> patch(prev_record->start() + unchanged_len,
-                       kUncompressibleBound);
-    OS::SNPrintF(patch, kBackwardReferenceFormat,
-                 best.distance, best.copy_from_pos);
-    prev_record->Truncate(unchanged_len + strlen(patch.start()));
+    Vector<char> backref(
+        prev_record->start() + unchanged_len, best.backref_size + 1);
+    PrintBackwardReference(backref, best.distance, best.copy_from_pos);
+    ASSERT(strlen(backref.start()) - best.backref_size == 0);
+    prev_record->Truncate(unchanged_len + best.backref_size);
   }
   return true;
 }

src/log-utils.h

@@ -88,48 +88,6 @@ class LogDynamicBuffer {
 };
 
 
-// An utility class for performing backward reference compression
-// of string ends. It operates using a window of previous strings.
-class LogRecordCompressor {
- public:
-  // 'window_size' is the size of backward lookup window.
-  // 'start_pos' is the length of string prefix that must be left uncompressed.
-  LogRecordCompressor(int window_size, int start_pos)
-      : buffer_(window_size), start_pos_(start_pos), curr_(-1), prev_(-1) {
-    // Must have place for the current record and the previous.
-    ASSERT(window_size >= 2);
-  }
-  ~LogRecordCompressor();
-
-  // Fills vector with a compressed version of the previous record.
-  // Returns false if there is no previous record.
-  bool RetrievePreviousCompressed(Vector<char>* prev_record);
-
-  // Stores a record if it differs from a previous one (or there's no previous).
-  // Returns true, if the record has been stored.
-  bool Store(const Vector<const char>& record);
-
- private:
-  // Record field separator. It is assumed that it can't appear
-  // inside a field (a simplified version of CSV format).
-  static const char kFieldSeparator = ',';
-
-  // Formatting string for back references.
-  static const char* kBackwardReferenceFormat;
-
-  // A boundary value. If current record only differs in
-  // kUncompressibleBound chars, don't compress it.
-  // The value must be greater than the length of maximum
-  // projected backward reference length.
-  static const intptr_t kUncompressibleBound = 10;
-
-  ScopedVector< Vector<const char> > buffer_;
-  const int start_pos_;
-  int curr_;
-  int prev_;
-};
-
-
 // Functions and data for performing output of log messages.
 class Log : public AllStatic {
  public:
@@ -156,9 +114,6 @@ class Log : public AllStatic {
     return !is_stopped_ && (output_handle_ != NULL || output_buffer_ != NULL);
   }
 
-  // Size of buffer used for record compression.
-  static const int kRecordCompressorWindow = 6;
-
  private:
   typedef int (*WritePtr)(const char* msg, int length);
 
@@ -214,12 +169,51 @@ class Log : public AllStatic {
   // mutex_ should be acquired before using it.
   static char* message_buffer_;
 
-  // An utility object for compressing repeated parts of records.
-  static LogRecordCompressor* record_compressor_;
+  friend class LogMessageBuilder;
+  friend class LogRecordCompressor;
+};
+
 
-  static const char* kCompressedTickEventName;
+// An utility class for performing backward reference compression
+// of string ends. It operates using a window of previous strings.
+class LogRecordCompressor {
+ public:
+  // 'window_size' is the size of backward lookup window.
+  explicit LogRecordCompressor(int window_size)
+      : buffer_(window_size + kNoCompressionWindowSize),
+        kMaxBackwardReferenceSize(
+            GetBackwardReferenceSize(window_size, Log::kMessageBufferSize)),
+        curr_(-1), prev_(-1) {
+  }
 
-  friend class LogMessageBuilder;
+  ~LogRecordCompressor();
+
+  // Fills vector with a compressed version of the previous record.
+  // Returns false if there is no previous record.
+  bool RetrievePreviousCompressed(Vector<char>* prev_record);
+
+  // Stores a record if it differs from a previous one (or there's no previous).
+  // Returns true, if the record has been stored.
+  bool Store(const Vector<const char>& record);
+
+ private:
+  // The minimum size of a buffer: a place needed for the current and
+  // the previous record. Since there is no place for precedessors of a previous
+  // record, it can't be compressed at all.
+  static const int kNoCompressionWindowSize = 2;
+
+  // Formatting strings for back references.
+  static const char* kLineBackwardReferenceFormat;
+  static const char* kBackwardReferenceFormat;
+
+  static int GetBackwardReferenceSize(int distance, int pos);
+
+  static void PrintBackwardReference(Vector<char> dest, int distance, int pos);
+
+  ScopedVector< Vector<const char> > buffer_;
+  const int kMaxBackwardReferenceSize;
+  int curr_;
+  int prev_;
 };
 
 
@@ -244,20 +238,28 @@ class LogMessageBuilder BASE_EMBEDDED {
   // Append a heap string.
   void Append(String* str);
 
+  // Appends an address, compressing it if needed by offsetting
+  // from Logger::last_address_.
+  void AppendAddress(Address addr);
+
+  // Appends an address, compressing it if needed.
+  void AppendAddress(Address addr, Address bias);
+
   void AppendDetailed(String* str, bool show_impl_info);
 
   // Stores log message into compressor, returns true if the message
-  // was stored (i.e. doesn't repeat the previous one). If log compression is
-  // disabled, does nothing and returns true.
-  bool StoreInCompressor();
+  // was stored (i.e. doesn't repeat the previous one).
+  bool StoreInCompressor(LogRecordCompressor* compressor);
 
   // Sets log message to a previous version of compressed message.
-  // Returns false, if there is no previous message. If log compression
-  // is disabled, does nothing and retuns true.
-  bool RetrieveCompressedPrevious() { return RetrieveCompressedPrevious(""); }
+  // Returns false, if there is no previous message.
+  bool RetrieveCompressedPrevious(LogRecordCompressor* compressor) {
+    return RetrieveCompressedPrevious(compressor, "");
+  }
 
   // Does the same at the version without arguments, and sets a prefix.
-  bool RetrieveCompressedPrevious(const char* prefix);
+  bool RetrieveCompressedPrevious(LogRecordCompressor* compressor,
+                                  const char* prefix);
 
   // Write the log message to the log file currently opened.
   void WriteToLogFile();

src/log.cc

@@ -303,7 +303,7 @@ VMState* Logger::current_state_ = NULL;
 VMState Logger::bottom_state_(EXTERNAL);
 SlidingStateWindow* Logger::sliding_state_window_ = NULL;
 const char** Logger::log_events_ = NULL;
-int Logger::tick_repeat_count_ = 0;
+CompressionHelper* Logger::compression_helper_ = NULL;
 
 #define DECLARE_LONG_EVENT(ignore1, long_name, ignore2) long_name,
 const char* kLongLogEventsNames[Logger::NUMBER_OF_LOG_EVENTS] = {
@@ -328,7 +328,7 @@ void Logger::ProfilerBeginEvent() {
   LogMessageBuilder msg;
   msg.Append("profiler,\"begin\",%d\n", kSamplingIntervalMs);
   if (FLAG_compress_log) {
-    msg.Append("profiler,\"compression\",%d\n", Log::kRecordCompressorWindow);
+    msg.Append("profiler,\"compression\",%d\n", kCompressionWindowSize);
   }
   msg.WriteToLogFile();
 }
@@ -629,9 +629,9 @@ void Logger::CodeCreateEvent(LogEventsAndTags tag,
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
-  msg.Append("%s,%s,0x%" V8PRIxPTR ",%d,\"",
-             log_events_[CODE_CREATION_EVENT], log_events_[tag],
-             code->address(), code->ExecutableSize());
+  msg.Append("%s,%s,", log_events_[CODE_CREATION_EVENT], log_events_[tag]);
+  msg.AppendAddress(code->address());
+  msg.Append(",%d,\"", code->ExecutableSize());
   for (const char* p = comment; *p != '\0'; p++) {
     if (*p == '"') {
       msg.Append('\\');
@@ -651,9 +651,9 @@ void Logger::CodeCreateEvent(LogEventsAndTags tag, Code* code, String* name) {
   LogMessageBuilder msg;
   SmartPointer<char> str =
       name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
-  msg.Append("%s,%s,0x%" V8PRIxPTR ",%d,\"%s\"\n",
-             log_events_[CODE_CREATION_EVENT], log_events_[tag],
-             code->address(), code->ExecutableSize(), *str);
+  msg.Append("%s,%s,", log_events_[CODE_CREATION_EVENT], log_events_[tag]);
+  msg.AppendAddress(code->address());
+  msg.Append(",%d,\"%s\"\n", code->ExecutableSize(), *str);
   msg.WriteToLogFile();
 #endif
 }
@@ -669,11 +669,10 @@ void Logger::CodeCreateEvent(LogEventsAndTags tag,
       name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   SmartPointer<char> sourcestr =
       source->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
-  msg.Append("%s,%s,0x%" V8PRIxPTR ",%d,\"%s %s:%d\"\n",
-             log_events_[CODE_CREATION_EVENT],
-             log_events_[tag], code->address(),
-             code->ExecutableSize(),
-             *str, *sourcestr, line);
+  msg.Append("%s,%s,", log_events_[CODE_CREATION_EVENT], log_events_[tag]);
+  msg.AppendAddress(code->address());
+  msg.Append(",%d,\"%s %s:%d\"\n",
+             code->ExecutableSize(), *str, *sourcestr, line);
   msg.WriteToLogFile();
 #endif
 }
@@ -683,12 +682,9 @@ void Logger::CodeCreateEvent(LogEventsAndTags tag, Code* code, int args_count) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
-  msg.Append("%s,%s,0x%" V8PRIxPTR ",%d,\"args_count: %d\"\n",
-             log_events_[CODE_CREATION_EVENT],
-             log_events_[tag],
-             code->address(),
-             code->ExecutableSize(),
-             args_count);
+  msg.Append("%s,%s,", log_events_[CODE_CREATION_EVENT], log_events_[tag]);
+  msg.AppendAddress(code->address());
+  msg.Append(",%d,\"args_count: %d\"\n", code->ExecutableSize(), args_count);
   msg.WriteToLogFile();
 #endif
 }
@@ -698,11 +694,10 @@ void Logger::RegExpCodeCreateEvent(Code* code, String* source) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
-  msg.Append("%s,%s,0x%" V8PRIxPTR ",%d,\"",
-             log_events_[CODE_CREATION_EVENT],
-             log_events_[REG_EXP_TAG],
-             code->address(),
-             code->ExecutableSize());
+  msg.Append("%s,%s,",
+             log_events_[CODE_CREATION_EVENT], log_events_[REG_EXP_TAG]);
+  msg.AppendAddress(code->address());
+  msg.Append(",%d,\"", code->ExecutableSize());
   msg.AppendDetailed(source, false);
   msg.Append("\"\n");
   msg.WriteToLogFile();
@@ -710,12 +705,57 @@ void Logger::RegExpCodeCreateEvent(Code* code, String* source) {
 }
 
 
+#ifdef ENABLE_LOGGING_AND_PROFILING
+
+// A class that contains all common code dealing with record compression.
+class CompressionHelper {
+ public:
+  explicit CompressionHelper(int window_size)
+      : compressor_(window_size), repeat_count_(0) { }
+
+  // Handles storing message in compressor, retrieving the previous one and
+  // prefixing it with repeat count, if needed.
+  // Returns true if message needs to be written to log.
+  bool HandleMessage(LogMessageBuilder* msg) {
+    if (!msg->StoreInCompressor(&compressor_)) {
+      // Current message repeats the previous one, don't write it.
+      ++repeat_count_;
+      return false;
+    }
+    if (repeat_count_ == 0) {
+      return msg->RetrieveCompressedPrevious(&compressor_);
+    }
+    OS::SNPrintF(prefix_, "%s,%d,",
+                 Logger::log_events_[Logger::REPEAT_META_EVENT],
+                 repeat_count_ + 1);
+    repeat_count_ = 0;
+    return msg->RetrieveCompressedPrevious(&compressor_, prefix_.start());
+  }
+
+ private:
+  LogRecordCompressor compressor_;
+  int repeat_count_;
+  EmbeddedVector<char, 20> prefix_;
+};
+
+#endif  // ENABLE_LOGGING_AND_PROFILING
+
+
 void Logger::CodeMoveEvent(Address from, Address to) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
+  static Address prev_to_ = NULL;
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
-  msg.Append("%s,0x%" V8PRIxPTR ",0x%" V8PRIxPTR "\n",
-             log_events_[CODE_MOVE_EVENT], from, to);
+  msg.Append("%s,", log_events_[CODE_MOVE_EVENT]);
+  msg.AppendAddress(from);
+  msg.Append(',');
+  msg.AppendAddress(to, prev_to_);
+  prev_to_ = to;
+  if (FLAG_compress_log) {
+    ASSERT(compression_helper_ != NULL);
+    if (!compression_helper_->HandleMessage(&msg)) return;
+  }
+  msg.Append('\n');
   msg.WriteToLogFile();
 #endif
 }
@@ -725,7 +765,13 @@ void Logger::CodeDeleteEvent(Address from) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
-  msg.Append("%s,0x%" V8PRIxPTR "\n", log_events_[CODE_DELETE_EVENT], from);
+  msg.Append("%s,", log_events_[CODE_DELETE_EVENT]);
+  msg.AppendAddress(from);
+  if (FLAG_compress_log) {
+    ASSERT(compression_helper_ != NULL);
+    if (!compression_helper_->HandleMessage(&msg)) return;
+  }
+  msg.Append('\n');
   msg.WriteToLogFile();
 #endif
 }
@@ -830,50 +876,27 @@ void Logger::DebugEvent(const char* event_type, Vector<uint16_t> parameter) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
 void Logger::TickEvent(TickSample* sample, bool overflow) {
   if (!Log::IsEnabled() || !FLAG_prof) return;
+  static Address prev_sp = NULL;
   LogMessageBuilder msg;
-  msg.Append("%s,0x%" V8PRIxPTR ",0x%" V8PRIxPTR ",%d",
-             log_events_[TICK_EVENT],
-             sample->pc, sample->sp, static_cast<int>(sample->state));
+  msg.Append("%s,", log_events_[TICK_EVENT]);
+  Address prev_addr = reinterpret_cast<Address>(sample->pc);
+  msg.AppendAddress(prev_addr);
+  msg.Append(',');
+  msg.AppendAddress(reinterpret_cast<Address>(sample->sp), prev_sp);
+  prev_sp = reinterpret_cast<Address>(sample->sp);
+  msg.Append(",%d", static_cast<int>(sample->state));
   if (overflow) {
     msg.Append(",overflow");
   }
-  uintptr_t prev_ptr = sample->pc;
   for (int i = 0; i < sample->frames_count; ++i) {
-    if (FLAG_compress_log) {
-      const uintptr_t ptr = OffsetFrom(sample->stack[i]);
-      intptr_t delta = ptr - prev_ptr;
-      prev_ptr = ptr;
-      // To avoid printing negative offsets in an unsigned form,
-      // we are printing an absolute value with a sign.
-      const char sign = delta >= 0 ? '+' : '-';
-      if (sign == '-') { delta = -delta; }
-      msg.Append(",%c0x%" V8PRIxPTR, sign, delta);
-    } else {
-      msg.Append(",0x%" V8PRIxPTR, sample->stack[i]);
-    }
+    msg.Append(',');
+    msg.AppendAddress(sample->stack[i], prev_addr);
+    prev_addr = sample->stack[i];
   }
-  // In case if log compression is disabled, the flow is straightforward,
-  // because both StoreInCompressor and RetrieveCompressedPrevious do nothing
-  // and just return 'true'. Otherwise, to perform compression of repeated
-  // tick events, instead of the current event, the previous one is written.
-  if (!msg.StoreInCompressor()) {
-    // Current message repeats the previous one, don't write it.
-    ++tick_repeat_count_;
-    return;
-  }
-
-  bool has_previous_message;
-  if (tick_repeat_count_ > 0) {
-    EmbeddedVector<char, 20> prefix;
-    OS::SNPrintF(prefix, "%s,%d,",
-                 log_events_[REPEAT_META_EVENT],
-                 tick_repeat_count_ + 1);
-    tick_repeat_count_ = 0;
-    has_previous_message = msg.RetrieveCompressedPrevious(prefix.start());
-  } else {
-    has_previous_message = msg.RetrieveCompressedPrevious();
+  if (FLAG_compress_log) {
+    ASSERT(compression_helper_ != NULL);
+    if (!compression_helper_->HandleMessage(&msg)) return;
   }
-  if (!has_previous_message) return;
   msg.Append('\n');
   msg.WriteToLogFile();
 }
@@ -1078,6 +1101,12 @@ bool Logger::Setup() {
     sliding_state_window_ = new SlidingStateWindow();
   }
 
+  log_events_ = FLAG_compress_log ?
+      kCompressedLogEventsNames : kLongLogEventsNames;
+  if (FLAG_compress_log) {
+    compression_helper_ = new CompressionHelper(kCompressionWindowSize);
+  }
+
   if (FLAG_prof) {
     profiler_ = new Profiler();
     if (!FLAG_prof_auto)
@@ -1087,9 +1116,6 @@ bool Logger::Setup() {
 
   LogMessageBuilder::set_write_failure_handler(StopLoggingAndProfiling);
 
-  log_events_ = FLAG_compress_log ?
-      kCompressedLogEventsNames : kLongLogEventsNames;
-
   return true;
 
 #else
@@ -1109,6 +1135,9 @@ void Logger::TearDown() {
     profiler_ = NULL;
   }
 
+  delete compression_helper_;
+  compression_helper_ = NULL;
+
   delete sliding_state_window_;
   sliding_state_window_ = NULL;
 

src/log.h

@@ -71,6 +71,7 @@ class Profiler;
 class Semaphore;
 class SlidingStateWindow;
 class LogMessageBuilder;
+class CompressionHelper;
 
 #undef LOG
 #ifdef ENABLE_LOGGING_AND_PROFILING
@@ -256,6 +257,9 @@ class Logger {
   // Profiler's sampling interval (in milliseconds).
   static const int kSamplingIntervalMs = 1;
 
+  // Size of window used for log records compression.
+  static const int kCompressionWindowSize = 4;
+
   // Emits the profiler's first message.
   static void ProfilerBeginEvent();
 
@@ -300,11 +304,12 @@ class Logger {
   // An array of log events names.
   static const char** log_events_;
 
-  // Counter for repeated tick events.
-  static int tick_repeat_count_;
+  // An instance of helper created if log compression is enabled.
+  static CompressionHelper* compression_helper_;
 
   // Internal implementation classes with access to
   // private members.
+  friend class CompressionHelper;
   friend class EventLog;
   friend class TimeLog;
   friend class Profiler;

test/cctest/test-log-utils.cc

@@ -139,7 +139,7 @@ TEST(DynaBufSealing) {
 
 
 TEST(CompressorStore) {
-  LogRecordCompressor comp(2, 0);
+  LogRecordCompressor comp(2);
   const Vector<const char> empty = CStrVector("");
   CHECK(comp.Store(empty));
   CHECK(!comp.Store(empty));
@@ -169,7 +169,7 @@ void CheckCompression(LogRecordCompressor* comp,
 
 
 TEST(CompressorNonCompressed) {
-  LogRecordCompressor comp(2, 0);
+  LogRecordCompressor comp(0);
   CHECK(!comp.RetrievePreviousCompressed(NULL));
   const Vector<const char> empty = CStrVector("");
   CHECK(comp.Store(empty));
@@ -185,7 +185,7 @@ TEST(CompressorNonCompressed) {
 
 
 TEST(CompressorSingleLine) {
-  LogRecordCompressor comp(3, strlen("xxx,"));
+  LogRecordCompressor comp(1);
   const Vector<const char> string_1 = CStrVector("eee,ddd,ccc,bbb,aaa");
   CHECK(comp.Store(string_1));
   const Vector<const char> string_2 = CStrVector("fff,ddd,ccc,bbb,aaa");
@@ -196,14 +196,14 @@ TEST(CompressorSingleLine) {
   const Vector<const char> string_3 = CStrVector("hhh,ggg,ccc,bbb,aaa");
   CHECK(comp.Store(string_3));
   // string_2 compressed using string_1.
-  CheckCompression(&comp, "fff,#1:4");
-  CheckCompression(&comp, "fff,#1:4");
+  CheckCompression(&comp, "fff#1:3");
+  CheckCompression(&comp, "fff#1:3");
   CHECK(!comp.Store(string_3));
   // Expecting no changes.
-  CheckCompression(&comp, "fff,#1:4");
+  CheckCompression(&comp, "fff#1:3");
   CHECK(!comp.Store(string_3));
   // Expecting no changes.
-  CheckCompression(&comp, "fff,#1:4");
+  CheckCompression(&comp, "fff#1:3");
   const Vector<const char> string_4 = CStrVector("iii,hhh,ggg,ccc,bbb,aaa");
   CHECK(comp.Store(string_4));
   // string_3 compressed using string_2.
@@ -211,7 +211,7 @@ TEST(CompressorSingleLine) {
   const Vector<const char> string_5 = CStrVector("nnn,mmm,lll,kkk,jjj");
   CHECK(comp.Store(string_5));
   // string_4 compressed using string_3.
-  CheckCompression(&comp, "iii,#1:0");
+  CheckCompression(&comp, "iii,#1");
   const Vector<const char> string_6 = CStrVector("nnn,mmmmmm,lll,kkk,jjj");
   CHECK(comp.Store(string_6));
   // string_5 hasn't been compressed.
@@ -226,12 +226,12 @@ TEST(CompressorSingleLine) {
   const Vector<const char> string_8 = CStrVector("xxn,mmm,lll,kkk,jjj");
   CHECK(comp.Store(string_8));
   // string_7 compressed using string_5.
-  CheckCompression(&comp, "nnnn#1:1");
+  CheckCompression(&comp, "nnn#1");
   const Vector<const char> string_9 =
       CStrVector("aaaaaaaaaaaaa,bbbbbbbbbbbbbbbbb");
   CHECK(comp.Store(string_9));
   // string_8 compressed using string_7.
-  CheckCompression(&comp, "xxn,#1:7");
+  CheckCompression(&comp, "xx#1:5");
   const Vector<const char> string_10 =
       CStrVector("aaaaaaaaaaaaa,cccccccbbbbbbbbbb");
   CHECK(comp.Store(string_10));
@@ -245,8 +245,8 @@ TEST(CompressorSingleLine) {
 
 
 TEST(CompressorMultiLines) {
-  const int kWindowSize = 5;
-  LogRecordCompressor comp(kWindowSize, strlen("xxx,"));
+  const int kWindowSize = 3;
+  LogRecordCompressor comp(kWindowSize);
   const Vector<const char> string_1 = CStrVector("eee,ddd,ccc,bbb,aaa");
   CHECK(comp.Store(string_1));
   const Vector<const char> string_2 = CStrVector("iii,hhh,ggg,fff,aaa");
@@ -258,22 +258,22 @@ TEST(CompressorMultiLines) {
   const Vector<const char> string_5 = CStrVector("ooo,lll,kkk,jjj,aaa");
   CHECK(comp.Store(string_5));
   // string_4 compressed using string_2.
-  CheckCompression(&comp, "nnn,#2:4");
+  CheckCompression(&comp, "nnn#2:3");
   CHECK(comp.Store(string_1));
   // string_5 compressed using string_3.
-  CheckCompression(&comp, "ooo,#2:4");
+  CheckCompression(&comp, "ooo#2:3");
   CHECK(comp.Store(string_4));
   // string_1 is out of buffer by now, so it shouldn't be compressed.
-  CHECK_GE(5, kWindowSize);
+  CHECK_GE(3, kWindowSize);
   CheckCompression(&comp, string_1);
   CHECK(comp.Store(string_2));
   // string_4 compressed using itself.
-  CheckCompression(&comp, "nnn,#3:4");
+  CheckCompression(&comp, "#3");
 }
 
 
 TEST(CompressorBestSelection) {
-  LogRecordCompressor comp(5, strlen("xxx,"));
+  LogRecordCompressor comp(3);
   const Vector<const char> string_1 = CStrVector("eee,ddd,ccc,bbb,aaa");
   CHECK(comp.Store(string_1));
   const Vector<const char> string_2 = CStrVector("ddd,ccc,bbb,aaa");
@@ -281,12 +281,29 @@ TEST(CompressorBestSelection) {
   const Vector<const char> string_3 = CStrVector("fff,eee,ddd,ccc,bbb,aaa");
   CHECK(comp.Store(string_3));
   // string_2 compressed using string_1.
-  CheckCompression(&comp, "ddd,#1:8");
+  CheckCompression(&comp, "#1:4");
   const Vector<const char> string_4 = CStrVector("nnn,hhh,ggg,fff,aaa");
   CHECK(comp.Store(string_4));
   // Compressing string_3 using string_1 gives a better compression than
   // using string_2.
-  CheckCompression(&comp, "fff,#2:0");
+  CheckCompression(&comp, "fff,#2");
+}
+
+
+TEST(CompressorCompressibility) {
+  LogRecordCompressor comp(2);
+  const Vector<const char> string_1 = CStrVector("eee,ddd,ccc,bbb,aaa");
+  CHECK(comp.Store(string_1));
+  const Vector<const char> string_2 = CStrVector("ccc,bbb,aaa");
+  CHECK(comp.Store(string_2));
+  const Vector<const char> string_3 = CStrVector("aaa");
+  CHECK(comp.Store(string_3));
+  // string_2 compressed using string_1.
+  CheckCompression(&comp, "#1:8");
+  const Vector<const char> string_4 = CStrVector("xxx");
+  CHECK(comp.Store(string_4));
+  // string_3 can't be compressed using string_2 --- too short.
+  CheckCompression(&comp, string_3);
 }
 
 #endif  // ENABLE_LOGGING_AND_PROFILING