Version 3.0.2.

src/log.cc

 // Copyright 2009 the V8 project authors. All rights reserved.
 // Redistribution and use in source and binary forms, with or without
 // modification, are permitted provided that the following conditions are
 // met:
 //
 //     * Redistributions of source code must retain the above copyright
 //       notice, this list of conditions and the following disclaimer.
 //     * Redistributions in binary form must reproduce the above
 //       copyright notice, this list of conditions and the following
 //       disclaimer in the documentation and/or other materials provided
@@ skipping 285 matching lines @@
   }
 
   // Start thread processing the profiler buffer.
   running_ = true;
   Start();
 
   // Register to get ticks.
   Logger::ticker_->SetProfiler(this);
 
   Logger::ProfilerBeginEvent();
+  Logger::LogAliases();
 }
 
 
 void Profiler::Disengage() {
   if (!engaged_) return;
 
   // Stop receiving ticks.
   Logger::ticker_->ClearProfiler();
 
   // Terminate the worker thread by setting running_ to false,
@@ skipping 19 matching lines @@
   }
 }
 
 
 //
 // Logger class implementation.
 //
 Ticker* Logger::ticker_ = NULL;
 Profiler* Logger::profiler_ = NULL;
 SlidingStateWindow* Logger::sliding_state_window_ = NULL;
+const char** Logger::log_events_ = NULL;
+CompressionHelper* Logger::compression_helper_ = NULL;
 int Logger::logging_nesting_ = 0;
 int Logger::cpu_profiler_nesting_ = 0;
 int Logger::heap_profiler_nesting_ = 0;
 
-#define DECLARE_EVENT(ignore1, name) name,
-const char* kLogEventsNames[Logger::NUMBER_OF_LOG_EVENTS] = {
-  LOG_EVENTS_AND_TAGS_LIST(DECLARE_EVENT)
+#define DECLARE_LONG_EVENT(ignore1, long_name, ignore2) long_name,
+const char* kLongLogEventsNames[Logger::NUMBER_OF_LOG_EVENTS] = {
+  LOG_EVENTS_AND_TAGS_LIST(DECLARE_LONG_EVENT)
 };
-#undef DECLARE_EVENT
+#undef DECLARE_LONG_EVENT
+
+#define DECLARE_SHORT_EVENT(ignore1, ignore2, short_name) short_name,
+const char* kCompressedLogEventsNames[Logger::NUMBER_OF_LOG_EVENTS] = {
+  LOG_EVENTS_AND_TAGS_LIST(DECLARE_SHORT_EVENT)
+};
+#undef DECLARE_SHORT_EVENT
 
 
 void Logger::ProfilerBeginEvent() {
   if (!Log::IsEnabled()) return;
   LogMessageBuilder msg;
   msg.Append("profiler,\"begin\",%d\n", kSamplingIntervalMs);
+  if (FLAG_compress_log) {
+    msg.Append("profiler,\"compression\",%d\n", kCompressionWindowSize);
+  }
   msg.WriteToLogFile();
 }
 
+
+void Logger::LogAliases() {
+  if (!Log::IsEnabled() || !FLAG_compress_log) return;
+  LogMessageBuilder msg;
+  for (int i = 0; i < NUMBER_OF_LOG_EVENTS; ++i) {
+    msg.Append("alias,%s,%s\n",
+               kCompressedLogEventsNames[i], kLongLogEventsNames[i]);
+  }
+  msg.WriteToLogFile();
+}
+
 #endif  // ENABLE_LOGGING_AND_PROFILING
 
 
 void Logger::StringEvent(const char* name, const char* value) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (FLAG_log) UncheckedStringEvent(name, value);
 #endif
 }
 
 
@@ skipping 284 matching lines @@
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (!Log::IsEnabled() || !FLAG_log) return;
   LogMessageBuilder msg;
   msg.Append("delete,%s,0x%" V8PRIxPTR "\n", name, object);
   msg.WriteToLogFile();
 #endif
 }
 
 
 #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
+
+
+#ifdef ENABLE_LOGGING_AND_PROFILING
 void Logger::CallbackEventInternal(const char* prefix, const char* name,
                                    Address entry_point) {
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
   msg.Append("%s,%s,",
-             kLogEventsNames[CODE_CREATION_EVENT],
-             kLogEventsNames[CALLBACK_TAG]);
+             log_events_[CODE_CREATION_EVENT], log_events_[CALLBACK_TAG]);
   msg.AppendAddress(entry_point);
   msg.Append(",1,\"%s%s\"", prefix, name);
+  if (FLAG_compress_log) {
+    ASSERT(compression_helper_ != NULL);
+    if (!compression_helper_->HandleMessage(&msg)) return;
+  }
   msg.Append('\n');
   msg.WriteToLogFile();
 }
 #endif
 
 
 void Logger::CallbackEvent(String* name, Address entry_point) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   SmartPointer<char> str =
@@ skipping 31 matching lines @@
   }
 }
 
 
 void Logger::CodeCreateEvent(LogEventsAndTags tag,
                              Code* code,
                              const char* comment) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
-  msg.Append("%s,%s,",
-             kLogEventsNames[CODE_CREATION_EVENT],
-             kLogEventsNames[tag]);
+  msg.Append("%s,%s,", log_events_[CODE_CREATION_EVENT], log_events_[tag]);
   msg.AppendAddress(code->address());
   msg.Append(",%d,\"%s", code->ExecutableSize(), ComputeMarker(code));
   for (const char* p = comment; *p != '\0'; p++) {
     if (*p == '"') {
       msg.Append('\\');
     }
     msg.Append(*p);
   }
   msg.Append('"');
   LowLevelCodeCreateEvent(code, &msg);
+  if (FLAG_compress_log) {
+    ASSERT(compression_helper_ != NULL);
+    if (!compression_helper_->HandleMessage(&msg)) return;
+  }
   msg.Append('\n');
   msg.WriteToLogFile();
 #endif
 }
 
 
 void Logger::CodeCreateEvent(LogEventsAndTags tag, Code* code, String* name) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
   SmartPointer<char> str =
       name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
-  msg.Append("%s,%s,",
-             kLogEventsNames[CODE_CREATION_EVENT],
-             kLogEventsNames[tag]);
+  msg.Append("%s,%s,", log_events_[CODE_CREATION_EVENT], log_events_[tag]);
   msg.AppendAddress(code->address());
   msg.Append(",%d,\"%s%s\"", code->ExecutableSize(), ComputeMarker(code), *str);
   LowLevelCodeCreateEvent(code, &msg);
+  if (FLAG_compress_log) {
+    ASSERT(compression_helper_ != NULL);
+    if (!compression_helper_->HandleMessage(&msg)) return;
+  }
   msg.Append('\n');
   msg.WriteToLogFile();
 #endif
 }
 
 
 void Logger::CodeCreateEvent(LogEventsAndTags tag,
                              Code* code, String* name,
                              String* source, int line) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
   SmartPointer<char> str =
       name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   SmartPointer<char> sourcestr =
       source->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
-  msg.Append("%s,%s,",
-             kLogEventsNames[CODE_CREATION_EVENT],
-             kLogEventsNames[tag]);
+  msg.Append("%s,%s,", log_events_[CODE_CREATION_EVENT], log_events_[tag]);
   msg.AppendAddress(code->address());
   msg.Append(",%d,\"%s%s %s:%d\"",
              code->ExecutableSize(),
              ComputeMarker(code),
              *str,
              *sourcestr,
              line);
   LowLevelCodeCreateEvent(code, &msg);
+  if (FLAG_compress_log) {
+    ASSERT(compression_helper_ != NULL);
+    if (!compression_helper_->HandleMessage(&msg)) return;
+  }
   msg.Append('\n');
   msg.WriteToLogFile();
 #endif
 }
 
 
 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,",
-             kLogEventsNames[CODE_CREATION_EVENT],
-             kLogEventsNames[tag]);
+  msg.Append("%s,%s,", log_events_[CODE_CREATION_EVENT], log_events_[tag]);
   msg.AppendAddress(code->address());
   msg.Append(",%d,\"args_count: %d\"", code->ExecutableSize(), args_count);
   LowLevelCodeCreateEvent(code, &msg);
+  if (FLAG_compress_log) {
+    ASSERT(compression_helper_ != NULL);
+    if (!compression_helper_->HandleMessage(&msg)) return;
+  }
   msg.Append('\n');
   msg.WriteToLogFile();
 #endif
 }
 
 
 void Logger::CodeMovingGCEvent() {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (!Log::IsEnabled() || !FLAG_log_code || !FLAG_ll_prof) return;
   LogMessageBuilder msg;
-  msg.Append("%s\n", kLogEventsNames[CODE_MOVING_GC]);
+  msg.Append("%s\n", log_events_[CODE_MOVING_GC]);
   msg.WriteToLogFile();
   OS::SignalCodeMovingGC();
 #endif
 }
 
 
 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,",
-             kLogEventsNames[CODE_CREATION_EVENT],
-             kLogEventsNames[REG_EXP_TAG]);
+             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('\"');
   LowLevelCodeCreateEvent(code, &msg);
+  if (FLAG_compress_log) {
+    ASSERT(compression_helper_ != NULL);
+    if (!compression_helper_->HandleMessage(&msg)) return;
+  }
   msg.Append('\n');
   msg.WriteToLogFile();
 #endif
 }
 
 
 void Logger::CodeMoveEvent(Address from, Address to) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   MoveEventInternal(CODE_MOVE_EVENT, from, to);
 #endif
 }
 
 
 void Logger::CodeDeleteEvent(Address from) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   DeleteEventInternal(CODE_DELETE_EVENT, from);
 #endif
 }
 
 
 void Logger::SnapshotPositionEvent(Address addr, int pos) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (!Log::IsEnabled() || !FLAG_log_snapshot_positions) return;
   LogMessageBuilder msg;
-  msg.Append("%s,", kLogEventsNames[SNAPSHOT_POSITION_EVENT]);
+  msg.Append("%s,", log_events_[SNAPSHOT_POSITION_EVENT]);
   msg.AppendAddress(addr);
   msg.Append(",%d", pos);
+  if (FLAG_compress_log) {
+    ASSERT(compression_helper_ != NULL);
+    if (!compression_helper_->HandleMessage(&msg)) return;
+  }
   msg.Append('\n');
   msg.WriteToLogFile();
 #endif
 }
 
 
 void Logger::FunctionCreateEvent(JSFunction* function) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   // This function can be called from GC iterators (during Scavenge,
   // MC, and MS), so marking bits can be set on objects. That's
   // why unchecked accessors are used here.
+  static Address prev_code = NULL;
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
-  msg.Append("%s,", kLogEventsNames[FUNCTION_CREATION_EVENT]);
+  msg.Append("%s,", log_events_[FUNCTION_CREATION_EVENT]);
   msg.AppendAddress(function->address());
   msg.Append(',');
-  msg.AppendAddress(function->unchecked_code()->address());
+  msg.AppendAddress(function->unchecked_code()->address(), prev_code);
+  prev_code = function->unchecked_code()->address();
+  if (FLAG_compress_log) {
+    ASSERT(compression_helper_ != NULL);
+    if (!compression_helper_->HandleMessage(&msg)) return;
+  }
   msg.Append('\n');
   msg.WriteToLogFile();
 #endif
 }
 
 
 void Logger::FunctionCreateEventFromMove(JSFunction* function) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (function->unchecked_code() != Builtins::builtin(Builtins::LazyCompile)) {
     FunctionCreateEvent(function);
@@ skipping 13 matching lines @@
 #ifdef ENABLE_LOGGING_AND_PROFILING
   DeleteEventInternal(FUNCTION_DELETE_EVENT, from);
 #endif
 }
 
 
 #ifdef ENABLE_LOGGING_AND_PROFILING
 void Logger::MoveEventInternal(LogEventsAndTags event,
                                Address from,
                                Address to) {
+  static Address prev_to_ = NULL;
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
-  msg.Append("%s,", kLogEventsNames[event]);
+  msg.Append("%s,", log_events_[event]);
   msg.AppendAddress(from);
   msg.Append(',');
-  msg.AppendAddress(to);
+  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
 
 
 #ifdef ENABLE_LOGGING_AND_PROFILING
 void Logger::DeleteEventInternal(LogEventsAndTags event, Address from) {
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
-  msg.Append("%s,", kLogEventsNames[event]);
+  msg.Append("%s,", log_events_[event]);
   msg.AppendAddress(from);
+  if (FLAG_compress_log) {
+    ASSERT(compression_helper_ != NULL);
+    if (!compression_helper_->HandleMessage(&msg)) return;
+  }
   msg.Append('\n');
   msg.WriteToLogFile();
 }
 #endif
 
 
 void Logger::ResourceEvent(const char* name, const char* tag) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (!Log::IsEnabled() || !FLAG_log) return;
   LogMessageBuilder msg;
@@ skipping 167 matching lines @@
              parameter_string);
   DeleteArray(parameter_string);
   msg.WriteToLogFile();
 #endif
 }
 
 
 #ifdef ENABLE_LOGGING_AND_PROFILING
 void Logger::TickEvent(TickSample* sample, bool overflow) {
   if (!Log::IsEnabled() || !FLAG_prof) return;
+  static Address prev_sp = NULL;
+  static Address prev_function = NULL;
   LogMessageBuilder msg;
-  msg.Append("%s,", kLogEventsNames[TICK_EVENT]);
-  msg.AppendAddress(sample->pc);
+  msg.Append("%s,", log_events_[TICK_EVENT]);
+  Address prev_addr = sample->pc;
+  msg.AppendAddress(prev_addr);
   msg.Append(',');
-  msg.AppendAddress(sample->sp);
+  msg.AppendAddress(sample->sp, prev_sp);
+  prev_sp = sample->sp;
   msg.Append(',');
-  msg.AppendAddress(sample->function);
+  msg.AppendAddress(sample->function, prev_function);
+  prev_function = sample->function;
   msg.Append(",%d", static_cast<int>(sample->state));
   if (overflow) {
     msg.Append(",overflow");
   }
   for (int i = 0; i < sample->frames_count; ++i) {
     msg.Append(',');
-    msg.AppendAddress(sample->stack[i]);
+    msg.AppendAddress(sample->stack[i], prev_addr);
+    prev_addr = sample->stack[i];
+  }
+  if (FLAG_compress_log) {
+    ASSERT(compression_helper_ != NULL);
+    if (!compression_helper_->HandleMessage(&msg)) return;
   }
   msg.Append('\n');
   msg.WriteToLogFile();
 }
 
 
 int Logger::GetActiveProfilerModules() {
   int result = PROFILER_MODULE_NONE;
   if (profiler_ != NULL && !profiler_->paused()) {
     result |= PROFILER_MODULE_CPU;
@@ skipping 408 matching lines @@
   }
 
   if (FLAG_ll_prof) LogCodeInfo();
 
   ticker_ = new Ticker(kSamplingIntervalMs);
 
   if (FLAG_sliding_state_window && sliding_state_window_ == NULL) {
     sliding_state_window_ = new SlidingStateWindow();
   }
 
+  log_events_ = FLAG_compress_log ?
+      kCompressedLogEventsNames : kLongLogEventsNames;
+  if (FLAG_compress_log) {
+    compression_helper_ = new CompressionHelper(kCompressionWindowSize);
+  }
+
   if (start_logging) {
     logging_nesting_ = 1;
   }
 
   if (FLAG_prof) {
     profiler_ = new Profiler();
     if (!FLAG_prof_auto) {
       profiler_->pause();
     } else {
       logging_nesting_ = 1;
@@ skipping 27 matching lines @@
 #ifdef ENABLE_LOGGING_AND_PROFILING
   LogMessageBuilder::set_write_failure_handler(NULL);
 
   // Stop the profiler before closing the file.
   if (profiler_ != NULL) {
     profiler_->Disengage();
     delete profiler_;
     profiler_ = NULL;
   }
 
+  delete compression_helper_;
+  compression_helper_ = NULL;
+
   delete sliding_state_window_;
   sliding_state_window_ = NULL;
 
   delete ticker_;
   ticker_ = NULL;
 
   Log::Close();
 #endif
 }
 
@@ skipping 10 matching lines @@
   }
   // Otherwise, if the sliding state window computation has not been
   // started we do it now.
   if (sliding_state_window_ == NULL) {
     sliding_state_window_ = new SlidingStateWindow();
   }
 #endif
 }
 
 } }  // namespace v8::internal