Changed all log messages to be handled through the LogMessageBuilder instead ...

src/log.cc

Index: src/log.cc
===================================================================
--- src/log.cc	(revision 1284)
+++ src/log.cc	(working copy)
@@ -268,7 +268,10 @@
   ~LogMessageBuilder() { }
 
   void Append(const char* format, ...);
+  void Append(const char* format, va_list args);
   void Append(const char c);
+  void Append(String *str);
+  void AppendDetailed(String* str, bool show_impl_info);
 
   void WriteToLogFile();
 
@@ -291,9 +294,18 @@
                    Logger::kMessageBufferSize - pos_);
   va_list args;
   va_start(args, format);
-  int result = v8::internal::OS::VSNPrintF(buf, format, args);
+  Append(format, args);
   va_end(args);
+  ASSERT(pos_ <= Logger::kMessageBufferSize);
+}
 
+
+// Append string data to the log message.
+void LogMessageBuilder::Append(const char* format, va_list args) {
+  Vector<char> buf(Logger::message_buffer_ + pos_,
+                   Logger::kMessageBufferSize - pos_);
+  int result = v8::internal::OS::VSNPrintF(buf, format, args);
+
   // Result is -1 if output was truncated.
   if (result >= 0) {
     pos_ += result;
@@ -313,6 +325,46 @@
 }
 
 
+// Append a heap string.
+void LogMessageBuilder::Append(String* str) {
+  AssertNoAllocation no_heap_allocation;  // Ensure string stay valid.
+  StringShape shape(str);
+  int length = str->length(shape);
+  for (int i = 0; i < length; i++) {
+    Append(static_cast<char>(str->Get(shape, i)));
+  }
+}
+
+void LogMessageBuilder::AppendDetailed(String* str, bool show_impl_info) {
+  AssertNoAllocation no_heap_allocation;  // Ensure string stay valid.
+  StringShape shape(str);
+  int len = str->length(shape);
+  if (len > 0x1000)
+    len = 0x1000;
+  if (show_impl_info) {
+    Append(shape.IsAsciiRepresentation() ? 'a' : '2');
+    if (shape.IsExternal())
+      Append('e');
+    if (shape.IsSymbol())
+      Append('#');
+    Append(":%i:", str->length());
+  }
+  for (int i = 0; i < len; i++) {
+    uc32 c = str->Get(shape, i);
+    if (c > 0xff) {
+      Append("\\u%04x", c);
+    } else if (c < 32 || c > 126) {
+      Append("\\x%02x", c);
+    } else if (c == ',') {
+      Append("\\,");
+    } else if (c == '\\') {
+      Append("\\\\");
+    } else {
+      Append("%lc", c);
+    }
+  }
+}
+
 // Write the log message to the log file currently opened.
 void LogMessageBuilder::WriteToLogFile() {
   ASSERT(pos_ <= Logger::kMessageBufferSize);
@@ -338,8 +390,9 @@
 void Logger::Preamble(const char* content) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log_code) return;
-  ScopedLock sl(mutex_);
-  fprintf(logfile_, "%s", content);
+  LogMessageBuilder msg;
+  msg.Append("%s", content);
+  msg.WriteToLogFile();
 #endif
 }
 
@@ -354,8 +407,9 @@
 #ifdef ENABLE_LOGGING_AND_PROFILING
 void Logger::UncheckedStringEvent(const char* name, const char* value) {
   if (logfile_ == NULL) return;
-  ScopedLock sl(mutex_);
-  fprintf(logfile_, "%s,\"%s\"\n", name, value);
+  LogMessageBuilder msg;
+  msg.Append("%s,\"%s\"\n", name, value);
+  msg.WriteToLogFile();
 }
 #endif
 
@@ -363,8 +417,9 @@
 void Logger::IntEvent(const char* name, int value) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log) return;
-  ScopedLock sl(mutex_);
-  fprintf(logfile_, "%s,%d\n", name, value);
+  LogMessageBuilder msg;
+  msg.Append("%s,%d\n", name, value);
+  msg.WriteToLogFile();
 #endif
 }
 
@@ -372,9 +427,10 @@
 void Logger::HandleEvent(const char* name, Object** location) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log_handles) return;
-  ScopedLock sl(mutex_);
-  fprintf(logfile_, "%s,0x%x\n", name,
-          reinterpret_cast<unsigned int>(location));
+  LogMessageBuilder msg;
+  msg.Append("%s,0x%x\n", name,
+             reinterpret_cast<unsigned int>(location));
+  msg.WriteToLogFile();
 #endif
 }
 
@@ -385,10 +441,12 @@
 // FLAG_log_api is true.
 void Logger::ApiEvent(const char* format, ...) {
   ASSERT(logfile_ != NULL && FLAG_log_api);
-  ScopedLock sl(mutex_);
+  LogMessageBuilder msg;
   va_list ap;
   va_start(ap, format);
-  vfprintf(logfile_, format, ap);
+  msg.Append(format, ap);
+  va_end(ap);
+  msg.WriteToLogFile();
 }
 #endif
 
@@ -414,9 +472,10 @@
                                 unsigned end) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_prof) return;
-  ScopedLock sl(mutex_);
-  fprintf(logfile_, "shared-library,\"%s\",0x%08x,0x%08x\n", library_path,
-          start, end);
+  LogMessageBuilder msg;
+  msg.Append("shared-library,\"%s\",0x%08x,0x%08x\n", library_path,
+             start, end);
+  msg.WriteToLogFile();
 #endif
 }
 
@@ -426,79 +485,54 @@
                                 unsigned end) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_prof) return;
-  ScopedLock sl(mutex_);
-  fprintf(logfile_, "shared-library,\"%ls\",0x%08x,0x%08x\n", library_path,
-          start, end);
+  LogMessageBuilder msg;
+  msg.Append("shared-library,\"%ls\",0x%08x,0x%08x\n", library_path,
+             start, end);
+  msg.WriteToLogFile();
 #endif
 }
 
 
 #ifdef ENABLE_LOGGING_AND_PROFILING
-void Logger::LogString(Handle<String> str, bool show_impl_info) {
-  StringShape shape(*str);
-  int len = str->length(shape);
-  if (len > 0x1000)
-    len = 0x1000;
-  if (show_impl_info) {
-    fputc(shape.IsAsciiRepresentation() ? 'a' : '2', logfile_);
-    if (shape.IsExternal())
-      fputc('e', logfile_);
-    if (shape.IsSymbol())
-      fputc('#', logfile_);
-    fprintf(logfile_, ":%i:", str->length());
-  }
-  for (int i = 0; i < len; i++) {
-    uc32 c = str->Get(shape, i);
-    if (c > 0xff) {
-      fprintf(logfile_, "\\u%04x", c);
-    } else if (c < 32 || c > 126) {
-      fprintf(logfile_, "\\x%02x", c);
-    } else if (c == ',') {
-      fprintf(logfile_, "\\,");
-    } else if (c == '\\') {
-      fprintf(logfile_, "\\\\");
-    } else {
-      fprintf(logfile_, "%lc", c);
-    }
-  }
-}
-
 void Logger::LogRegExpSource(Handle<JSRegExp> regexp) {
   // Prints "/" + re.source + "/" +
   //      (re.global?"g":"") + (re.ignorecase?"i":"") + (re.multiline?"m":"")
+  LogMessageBuilder msg;
 
   Handle<Object> source = GetProperty(regexp, "source");
   if (!source->IsString()) {
-    fprintf(logfile_, "no source");
+    msg.Append("no source");
     return;
   }
 
   switch (regexp->TypeTag()) {
     case JSRegExp::ATOM:
-      fprintf(logfile_, "a");
+      msg.Append('a');
       break;
     default:
       break;
   }
-  fprintf(logfile_, "/");
-  LogString(Handle<String>::cast(source), false);
-  fprintf(logfile_, "/");
+  msg.Append('/');
+  msg.AppendDetailed(*Handle<String>::cast(source), false);
+  msg.Append('/');
 
   // global flag
   Handle<Object> global = GetProperty(regexp, "global");
   if (global->IsTrue()) {
-    fprintf(logfile_, "g");
+    msg.Append('g');
   }
   // ignorecase flag
   Handle<Object> ignorecase = GetProperty(regexp, "ignoreCase");
   if (ignorecase->IsTrue()) {
-    fprintf(logfile_, "i");
+    msg.Append('i');
   }
   // multiline flag
   Handle<Object> multiline = GetProperty(regexp, "multiline");
   if (multiline->IsTrue()) {
-    fprintf(logfile_, "m");
+    msg.Append('m');
   }
+
+  msg.WriteToLogFile();
 }
 #endif  // ENABLE_LOGGING_AND_PROFILING
 
@@ -506,19 +540,20 @@
 void Logger::RegExpCompileEvent(Handle<JSRegExp> regexp, bool in_cache) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log_regexp) return;
-  ScopedLock sl(mutex_);
-
-  fprintf(logfile_, "regexp-compile,");
+  LogMessageBuilder msg;
+  msg.Append("regexp-compile,");
   LogRegExpSource(regexp);
-  fprintf(logfile_, in_cache ? ",hit\n" : ",miss\n");
+  msg.Append(in_cache ? ",hit\n" : ",miss\n");
+  msg.WriteToLogFile();
 #endif
 }
 
 
 void Logger::LogRuntime(Vector<const char> format, JSArray* args) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  ScopedLock sl(mutex_);
+  if (logfile_ == NULL || !FLAG_log_runtime) return;
   HandleScope scope;
+  LogMessageBuilder msg;
   for (int i = 0; i < format.length(); i++) {
     char c = format[i];
     if (c == '%' && i <= format.length() - 2) {
@@ -528,28 +563,29 @@
       i++;
       switch (format[i]) {
         case 's':
-          Logger::LogString(Handle<String>(String::cast(obj)), false);
+          msg.AppendDetailed(String::cast(obj), false);
           break;
         case 'S':
-          Logger::LogString(Handle<String>(String::cast(obj)), true);
+          msg.AppendDetailed(String::cast(obj), true);
           break;
         case 'r':
           Logger::LogRegExpSource(Handle<JSRegExp>(JSRegExp::cast(obj)));
           break;
         case 'x':
-          fprintf(logfile_, "0x%x", Smi::cast(obj)->value());
+          msg.Append("0x%x", Smi::cast(obj)->value());
           break;
         case 'i':
-          fprintf(logfile_, "%i", Smi::cast(obj)->value());
+          msg.Append("%i", Smi::cast(obj)->value());
           break;
         default:
           UNREACHABLE();
       }
     } else {
-      fputc(c, logfile_);
+      msg.Append(c);
     }
   }
-  fputc('\n', logfile_);
+  msg.Append('\n');
+  msg.WriteToLogFile();
 #endif
 }
 
@@ -611,10 +647,11 @@
 void Logger::NewEvent(const char* name, void* object, size_t size) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log) return;
-  ScopedLock sl(mutex_);
-  fprintf(logfile_, "new,%s,0x%x,%u\n", name,
-          reinterpret_cast<unsigned int>(object),
-          static_cast<unsigned int>(size));
+  LogMessageBuilder msg;
+  msg.Append("new,%s,0x%x,%u\n", name,
+             reinterpret_cast<unsigned int>(object),
+             static_cast<unsigned int>(size));
+  msg.WriteToLogFile();
 #endif
 }
 
@@ -622,9 +659,10 @@
 void Logger::DeleteEvent(const char* name, void* object) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log) return;
-  ScopedLock sl(mutex_);
-  fprintf(logfile_, "delete,%s,0x%x\n", name,
-          reinterpret_cast<unsigned int>(object));
+  LogMessageBuilder msg;
+  msg.Append("delete,%s,0x%x\n", name,
+             reinterpret_cast<unsigned int>(object));
+  msg.WriteToLogFile();
 #endif
 }
 
@@ -637,7 +675,9 @@
              reinterpret_cast<unsigned int>(code->address()),
              code->instruction_size());
   for (const char* p = comment; *p != '\0'; p++) {
-    if (*p == '\"') fprintf(logfile_, "\\");
+    if (*p == '"') {
+      msg.Append('\\');
+    }
     msg.Append(*p);
   }
   msg.Append('"');
@@ -757,16 +797,17 @@
 void Logger::ResourceEvent(const char* name, const char* tag) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log) return;
-  ScopedLock sl(mutex_);
-  fprintf(logfile_, "%s,%s,", name, tag);
+  LogMessageBuilder msg;
+  msg.Append("%s,%s,", name, tag);
 
   uint32_t sec, usec;
   if (OS::GetUserTime(&sec, &usec) != -1) {
-    fprintf(logfile_, "%d,%d,", sec, usec);
+    msg.Append("%d,%d,", sec, usec);
   }
-  fprintf(logfile_, "%.0f", OS::TimeCurrentMillis());
+  msg.Append("%.0f", OS::TimeCurrentMillis());
 
-  fprintf(logfile_, "\n");
+  msg.Append('\n');
+  msg.WriteToLogFile();
 #endif
 }
 
@@ -774,15 +815,19 @@
 void Logger::SuspectReadEvent(String* name, Object* obj) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log_suspect) return;
+  LogMessageBuilder msg;
   String* class_name = obj->IsJSObject()
                        ? JSObject::cast(obj)->class_name()
                        : Heap::empty_string();
   ScopedLock sl(mutex_);
-  fprintf(logfile_, "suspect-read,");
-  class_name->PrintOn(logfile_);
-  fprintf(logfile_, ",\"");
-  name->PrintOn(logfile_);
-  fprintf(logfile_, "\"\n");
+  msg.Append("suspect-read,");
+  msg.Append(class_name);
+  msg.Append(',');
+  msg.Append('"');
+  msg.Append(name);
+  msg.Append('"');
+  msg.Append('\n');
+  msg.WriteToLogFile();
 #endif
 }
 
@@ -790,8 +835,9 @@
 void Logger::HeapSampleBeginEvent(const char* space, const char* kind) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log_gc) return;
-  ScopedLock sl(mutex_);
-  fprintf(logfile_, "heap-sample-begin,\"%s\",\"%s\"\n", space, kind);
+  LogMessageBuilder msg;
+  msg.Append("heap-sample-begin,\"%s\",\"%s\"\n", space, kind);
+  msg.WriteToLogFile();
 #endif
 }
 
@@ -799,8 +845,9 @@
 void Logger::HeapSampleEndEvent(const char* space, const char* kind) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log_gc) return;
-  ScopedLock sl(mutex_);
-  fprintf(logfile_, "heap-sample-end,\"%s\",\"%s\"\n", space, kind);
+  LogMessageBuilder msg;
+  msg.Append("heap-sample-end,\"%s\",\"%s\"\n", space, kind);
+  msg.WriteToLogFile();
 #endif
 }
 
@@ -808,8 +855,9 @@
 void Logger::HeapSampleItemEvent(const char* type, int number, int bytes) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log_gc) return;
-  ScopedLock sl(mutex_);
-  fprintf(logfile_, "heap-sample-item,%s,%d,%d\n", type, number, bytes);
+  LogMessageBuilder msg;
+  msg.Append("heap-sample-item,%s,%d,%d\n", type, number, bytes);
+  msg.WriteToLogFile();
 #endif
 }
 
@@ -817,8 +865,9 @@
 void Logger::DebugTag(const char* call_site_tag) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log) return;
-  ScopedLock sl(mutex_);
-  fprintf(logfile_, "debug-tag,%s\n", call_site_tag);
+  LogMessageBuilder msg;
+  msg.Append("debug-tag,%s\n", call_site_tag);
+  msg.WriteToLogFile();
 #endif
 }
 
@@ -831,13 +880,13 @@
     s.AddCharacter(static_cast<char>(parameter[i]));
   }
   char* parameter_string = s.Finalize();
-  ScopedLock sl(mutex_);
-  fprintf(logfile_,
-          "debug-queue-event,%s,%15.3f,%s\n",
-          event_type,
-          OS::TimeCurrentMillis(),
-          parameter_string);
+  LogMessageBuilder msg;
+  msg.Append("debug-queue-event,%s,%15.3f,%s\n",
+             event_type,
+             OS::TimeCurrentMillis(),
+             parameter_string);
   DeleteArray(parameter_string);
+  msg.WriteToLogFile();
 #endif
 }
 
@@ -845,11 +894,14 @@
 #ifdef ENABLE_LOGGING_AND_PROFILING
 void Logger::TickEvent(TickSample* sample, bool overflow) {
   if (logfile_ == NULL || !FLAG_prof) return;
-  ScopedLock sl(mutex_);
-  fprintf(logfile_, "tick,0x%x,0x%x,%d", sample->pc, sample->sp,
-          static_cast<int>(sample->state));
-  if (overflow) fprintf(logfile_, ",overflow");
-  fprintf(logfile_, "\n");
+  LogMessageBuilder msg;
+  msg.Append("tick,0x%x,0x%x,%d", sample->pc, sample->sp,
+             static_cast<int>(sample->state));
+  if (overflow) {
+    msg.Append(",overflow");
+  }
+  msg.Append('\n');
+  msg.WriteToLogFile();
 }
 
 
@@ -873,6 +925,7 @@
 #ifdef ENABLE_LOGGING_AND_PROFILING
   // --log-all enables all the log flags.
   if (FLAG_log_all) {
+    FLAG_log_runtime = true;
     FLAG_log_api = true;
     FLAG_log_code = true;
     FLAG_log_gc = true;
@@ -884,8 +937,8 @@
   // --prof implies --log-code.
   if (FLAG_prof) FLAG_log_code = true;
 
-  bool open_log_file = FLAG_log || FLAG_log_api || FLAG_log_code
-      || FLAG_log_gc || FLAG_log_handles || FLAG_log_suspect
+  bool open_log_file = FLAG_log || FLAG_log_runtime || FLAG_log_api
+      || FLAG_log_code || FLAG_log_gc || FLAG_log_handles || FLAG_log_suspect
       || FLAG_log_regexp || FLAG_log_state_changes;
 
   // If we're logging anything, we need to open the log file.