Add log compression ability.

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 244 matching lines @@
   OS::LogSharedLibraryAddresses();
 
   // Start thread processing the profiler buffer.
   running_ = true;
   Start();
 
   // Register to get ticks.
   Logger::ticker_->SetProfiler(this);
 
   Logger::ProfilerBeginEvent();
+  Logger::LogAliases();
 }
 
 
 void Profiler::Disengage() {
   // Stop receiving ticks.
   Logger::ticker_->ClearProfiler();
 
   // Terminate the worker thread by setting running_ to false,
   // inserting a fake element in the queue and then wait for
   // the thread to terminate.
@@ skipping 19 matching lines @@
 
 
 //
 // Logger class implementation.
 //
 Ticker* Logger::ticker_ = NULL;
 Profiler* Logger::profiler_ = NULL;
 VMState* Logger::current_state_ = NULL;
 VMState Logger::bottom_state_(EXTERNAL);
 SlidingStateWindow* Logger::sliding_state_window_ = NULL;
+const char** Logger::log_events_ = NULL;
+
+#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_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
 
 
 bool Logger::IsEnabled() {
   return Log::IsEnabled();
 }
 
 
 void Logger::ProfilerBeginEvent() {
   if (!Log::IsEnabled()) return;
   LogMessageBuilder msg;
   msg.Append("profiler,\"begin\",%d\n", kSamplingIntervalMs);
   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::Preamble(const char* content) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
   msg.WriteCStringToLogFile(content);
 #endif
 }
@@ skipping 259 matching lines @@
 void Logger::DeleteEvent(const char* name, void* object) {
 #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
 }
 
 
-void Logger::CodeCreateEvent(const char* tag, Code* code, const char* comment) {
+void Logger::CodeCreateEvent(

[Søren Thygesen Gjesse, 2009/06/08 12:28:47]

I think we normally use the following format for long argument lists:

void Logger::CodeCreateEvent(LogEventsAndTags tag,
                             Code* code,
                             const char* comment) {

[Mikhail Naganov, 2009/06/08 13:39:09]

OK, fixed.

+    LogEventsAndTags tag, Code* code, const char* comment) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
-  msg.Append("code-creation,%s,0x%" V8PRIxPTR ",%d,\"", tag, code->address(),
-             code->ExecutableSize());
+  msg.Append("%s,%s,0x%" V8PRIxPTR ",%d,\"",
+             log_events_[CODE_CREATION_EVENT], log_events_[tag],
+             code->address(), code->ExecutableSize());
   for (const char* p = comment; *p != '\0'; p++) {
     if (*p == '"') {
       msg.Append('\\');
     }
     msg.Append(*p);
   }
   msg.Append('"');
   msg.Append('\n');
   msg.WriteToLogFile();
 #endif
 }
 
 
-void Logger::CodeCreateEvent(const char* tag, Code* code, String* name) {
+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("code-creation,%s,0x%" V8PRIxPTR ",%d,\"%s\"\n",
-             tag, code->address(), code->ExecutableSize(), *str);
+  msg.Append("%s,%s,0x%" V8PRIxPTR ",%d,\"%s\"\n",
+             log_events_[CODE_CREATION_EVENT], log_events_[tag],
+             code->address(), code->ExecutableSize(), *str);
   msg.WriteToLogFile();
 #endif
 }
 
 
-void Logger::CodeCreateEvent(const char* tag, Code* code, String* name,
+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("code-creation,%s,0x%" V8PRIxPTR ",%d,\"%s %s:%d\"\n",
-             tag, code->address(),
+  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.WriteToLogFile();
 #endif
 }
 
 
-void Logger::CodeCreateEvent(const char* tag, Code* code, int args_count) {
+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("code-creation,%s,0x%" V8PRIxPTR ",%d,\"args_count: %d\"\n", tag,
+  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.WriteToLogFile();
 #endif
 }
 
 
 void Logger::RegExpCodeCreateEvent(Code* code, String* source) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
-  msg.Append("code-creation,%s,0x%" V8PRIxPTR ",%d,\"", "RegExp",
+  msg.Append("%s,%s,0x%" V8PRIxPTR ",%d,\"",
+             log_events_[CODE_CREATION_EVENT],
+             log_events_[REG_EXP_TAG],
              code->address(),
              code->ExecutableSize());
   msg.AppendDetailed(source, false);
   msg.Append("\"\n");
   msg.WriteToLogFile();
 #endif
 }
 
 
-void Logger::CodeAllocateEvent(Code* code, Assembler* assem) {
-#ifdef ENABLE_LOGGING_AND_PROFILING
-  if (!Log::IsEnabled() || !FLAG_log_code) return;
-  LogMessageBuilder msg;
-  msg.Append("code-allocate,0x%" V8PRIxPTR ",0x%" V8PRIxPTR "\n",
-             code->address(),
-             assem);
-  msg.WriteToLogFile();
-#endif
-}
-
-
 void Logger::CodeMoveEvent(Address from, Address to) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
-  msg.Append("code-move,0x%" V8PRIxPTR ",0x%" V8PRIxPTR "\n", from, to);
+  msg.Append("%s,0x%" V8PRIxPTR ",0x%" V8PRIxPTR "\n",
+             log_events_[CODE_MOVE_EVENT], from, to);
   msg.WriteToLogFile();
 #endif
 }
 
 
 void Logger::CodeDeleteEvent(Address from) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (!Log::IsEnabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
-  msg.Append("code-delete,0x%" V8PRIxPTR "\n", from);
+  msg.Append("%s,0x%" V8PRIxPTR "\n", log_events_[CODE_DELETE_EVENT], from);
   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;
   msg.Append("%s,%s,", name, tag);
@@ skipping 85 matching lines @@
   DeleteArray(parameter_string);
   msg.WriteToLogFile();
 #endif
 }
 
 
 #ifdef ENABLE_LOGGING_AND_PROFILING
 void Logger::TickEvent(TickSample* sample, bool overflow) {
   if (!Log::IsEnabled() || !FLAG_prof) return;
   LogMessageBuilder msg;
-  msg.Append("tick,0x%" V8PRIxPTR ",0x%" V8PRIxPTR ",%d",
+  msg.Append("%s,0x%" V8PRIxPTR ",0x%" V8PRIxPTR ",%d",
+             log_events_[TICK_EVENT],
              sample->pc, sample->sp, 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) {
-    msg.Append(",0x%" V8PRIxPTR, sample->stack[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('\n');
   msg.WriteToLogFile();
 }
 
 
 bool Logger::IsProfilerPaused() {
   return profiler_->paused();
 }
 
@@ skipping 83 matching lines @@
     Handle<String> name(String::cast(shared->name()));
     Handle<String> func_name(name->length() > 0 ?
                              *name : shared->inferred_name());
     if (shared->script()->IsScript()) {
       Handle<Script> script(Script::cast(shared->script()));
       if (script->name()->IsString()) {
         Handle<String> script_name(String::cast(script->name()));
         int line_num = GetScriptLineNumber(script, shared->start_position());
         if (line_num > 0) {
           line_num += script->line_offset()->value() + 1;
-          LOG(CodeCreateEvent("LazyCompile", shared->code(), *func_name,
+          LOG(CodeCreateEvent(Logger::LAZY_COMPILE_TAG,
+                              shared->code(), *func_name,
                               *script_name, line_num));
         } else {
           // Can't distinguish enum and script here, so always use Script.
-          LOG(CodeCreateEvent("Script", shared->code(), *script_name));
+          LOG(CodeCreateEvent(Logger::SCRIPT_TAG,
+                              shared->code(), *script_name));
         }
         continue;
       }
     }
     // If no script or script has no name.
-    LOG(CodeCreateEvent("LazyCompile", shared->code(), *func_name));
+    LOG(CodeCreateEvent(Logger::LAZY_COMPILE_TAG, shared->code(), *func_name));
   }
 
   DeleteArray(sfis);
 }
 
 #endif
 
 
 bool Logger::Setup() {
 #ifdef ENABLE_LOGGING_AND_PROFILING
@@ skipping 78 matching lines @@
 
   if (FLAG_prof) {
     profiler_ = new Profiler();
     if (!FLAG_prof_auto)
       profiler_->pause();
     profiler_->Engage();
   }
 
   LogMessageBuilder::set_write_failure_handler(StopLoggingAndProfiling);
 
+  log_events_ = FLAG_compress_log ?
+      kCompressedLogEventsNames : kLongLogEventsNames;
+
   return true;
 
 #else
   return false;
 #endif
 }
 
 
 void Logger::TearDown() {
 #ifdef ENABLE_LOGGING_AND_PROFILING
@@ skipping 111 matching lines @@
     } else if (previous_->state_ == EXTERNAL) {
       // We are leaving V8.
       Heap::Protect();
     }
   }
 #endif
 }
 #endif
 
 } }  // namespace v8::internal