First step in refactoring the logging system to allow the logging messages to...

src/log.cc

 // Copyright 2006-2008 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 241 matching lines @@
 void Profiler::Run() {
   TickSample sample;
   bool overflow = Logger::profiler_->Remove(&sample);
   while (running_) {
     LOG(TickEvent(&sample, overflow));
     overflow = Logger::profiler_->Remove(&sample);
   }
 }
 
 
+#ifdef ENABLE_LOGGING_AND_PROFILING
+// Utility class for formatting log messages. It fills the message into the
+// static buffer in Logger.
+class LogMessageBuilder BASE_EMBEDDED {
+ public:
+  explicit LogMessageBuilder();
+  ~LogMessageBuilder() { }
+
+  void Append(const char* format, ...);
+  void Append(const char c);
+
+  void WriteToLogFile();
+
+ private:
+  ScopedLock sl;
+  int pos_;
+};
+
+
+// Create a message builder starting from position 0. This acquires the mutex
+// in the logger as well.
+LogMessageBuilder::LogMessageBuilder(): pos_(0), sl(Logger::mutex_) {
+  ASSERT(Logger::message_buffer_ != NULL);
+}
+
+
+// Append string data to the log message.
+void LogMessageBuilder::Append(const char* format, ...) {
+  Vector<char> buf(Logger::message_buffer_ + pos_,
+                   Logger::kMessageBufferSize - pos_);
+  va_list args;
+  va_start(args, format);
+  int result = v8::internal::OS::VSNPrintF(buf, format, args);
+  va_end(args);
+
+  // Result is -1 if output was truncated.
+  if (result >= 0) {
+    pos_ += result;
+  } else {
+    pos_ = Logger::kMessageBufferSize;
+  }
+  ASSERT(pos_ <= Logger::kMessageBufferSize);
+}
+
+
+// Append a character to the log message.
+void LogMessageBuilder::Append(const char c) {
+  if (pos_ < Logger::kMessageBufferSize) {
+    Logger::message_buffer_[pos_++] = c;
+  }
+  ASSERT(pos_ <= Logger::kMessageBufferSize);
+}
+
+
+// Write the log message to the log file currently opened.
+void LogMessageBuilder::WriteToLogFile() {
+  ASSERT(pos_ <= Logger::kMessageBufferSize);
+  fwrite(Logger::message_buffer_, 1, pos_, Logger::logfile_);
+}
+#endif
+
+
 //
 // Logger class implementation.
 //
 Ticker* Logger::ticker_ = NULL;
+char* Logger::message_buffer_ = NULL;
 FILE* Logger::logfile_ = NULL;
 Profiler* Logger::profiler_ = NULL;
 Mutex* Logger::mutex_ = NULL;
 VMState* Logger::current_state_ = NULL;
 SlidingStateWindow* Logger::sliding_state_window_ = NULL;
 
 #endif  // ENABLE_LOGGING_AND_PROFILING
 
+
 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);
 #endif
 }
 
 
 void Logger::StringEvent(const char* name, const char* value) {
@@ skipping 277 matching lines @@
   ScopedLock sl(mutex_);
   fprintf(logfile_, "delete,%s,0x%x\n", name,
           reinterpret_cast<unsigned int>(object));
 #endif
 }
 
 
 void Logger::CodeCreateEvent(const char* tag, Code* code, const char* comment) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log_code) return;
-  ScopedLock sl(mutex_);
-
-  fprintf(logfile_, "code-creation,%s,0x%x,%d,\"", tag,
-          reinterpret_cast<unsigned int>(code->address()),
-          code->instruction_size());
+  LogMessageBuilder msg;
+  msg.Append("code-creation,%s,0x%x,%d,\"", tag,
+             reinterpret_cast<unsigned int>(code->address()),
+             code->instruction_size());
   for (const char* p = comment; *p != '\0'; p++) {
     if (*p == '\"') fprintf(logfile_, "\\");
-    fprintf(logfile_, "%c", *p);
+    msg.Append(*p);
   }
-  fprintf(logfile_, "\"\n");
+  msg.Append('"');
+  msg.Append('\n');
+  msg.WriteToLogFile();
 #endif
 }
 
 
 void Logger::CodeCreateEvent(const char* tag, Code* code, String* name) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log_code) return;
-  ScopedLock sl(mutex_);
+  LogMessageBuilder msg;
   SmartPointer<char> str =
       name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
-  fprintf(logfile_, "code-creation,%s,0x%x,%d,\"%s\"\n", tag,
-          reinterpret_cast<unsigned int>(code->address()),
-          code->instruction_size(), *str);
+  msg.Append("code-creation,%s,0x%x,%d,\"%s\"\n", tag,
+             reinterpret_cast<unsigned int>(code->address()),
+             code->instruction_size(), *str);
+  msg.WriteToLogFile();
 #endif
 }
 
 
 void Logger::CodeCreateEvent(const char* tag, Code* code, String* name,
                              String* source, int line) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log_code) return;
-  ScopedLock sl(mutex_);
+  LogMessageBuilder msg;
   SmartPointer<char> str =
       name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
   SmartPointer<char> sourcestr =
       source->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
-  fprintf(logfile_, "code-creation,%s,0x%x,%d,\"%s %s:%d\"\n", tag,
-          reinterpret_cast<unsigned int>(code->address()),
-          code->instruction_size(), *str, *sourcestr, line);
+  msg.Append("code-creation,%s,0x%x,%d,\"%s %s:%d\"\n", tag,
+             reinterpret_cast<unsigned int>(code->address()),
+             code->instruction_size(), *str, *sourcestr, line);
+  msg.WriteToLogFile();
 #endif
 }
 
 
 void Logger::CodeCreateEvent(const char* tag, Code* code, int args_count) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log_code) return;
-  ScopedLock sl(mutex_);
-
-  fprintf(logfile_, "code-creation,%s,0x%x,%d,\"args_count: %d\"\n", tag,
-          reinterpret_cast<unsigned int>(code->address()),
-          code->instruction_size(),
-          args_count);
+  LogMessageBuilder msg;
+  msg.Append("code-creation,%s,0x%x,%d,\"args_count: %d\"\n", tag,
+             reinterpret_cast<unsigned int>(code->address()),
+             code->instruction_size(),
+             args_count);
+  msg.WriteToLogFile();
 #endif
 }
 
 
 void Logger::CodeAllocateEvent(Code* code, Assembler* assem) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log_code) return;
-  ScopedLock sl(mutex_);
-
-  fprintf(logfile_, "code-allocate,0x%x,0x%x\n",
-          reinterpret_cast<unsigned int>(code->address()),
-          reinterpret_cast<unsigned int>(assem));
+  LogMessageBuilder msg;
+  msg.Append("code-allocate,0x%x,0x%x\n",
+             reinterpret_cast<unsigned int>(code->address()),
+             reinterpret_cast<unsigned int>(assem));
+  msg.WriteToLogFile();
 #endif
 }
 
 
 void Logger::CodeMoveEvent(Address from, Address to) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log_code) return;
-  ScopedLock sl(mutex_);
-  fprintf(logfile_, "code-move,0x%x,0x%x\n",
-          reinterpret_cast<unsigned int>(from),
-          reinterpret_cast<unsigned int>(to));
+  LogMessageBuilder msg;
+  msg.Append("code-move,0x%x,0x%x\n",
+             reinterpret_cast<unsigned int>(from),
+             reinterpret_cast<unsigned int>(to));
+  msg.WriteToLogFile();
 #endif
 }
 
 
 void Logger::CodeDeleteEvent(Address from) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log_code) return;
-  ScopedLock sl(mutex_);
-  fprintf(logfile_, "code-delete,0x%x\n", reinterpret_cast<unsigned int>(from));
+  LogMessageBuilder msg;
+  msg.Append("code-delete,0x%x\n", reinterpret_cast<unsigned int>(from));
+  msg.WriteToLogFile();
 #endif
 }
 
 
 void Logger::BeginCodeRegionEvent(CodeRegion* region,
                                   Assembler* masm,
                                   const char* name) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log_code) return;
-  ScopedLock sl(mutex_);
-  fprintf(logfile_, "begin-code-region,0x%x,0x%x,0x%x,%s\n",
-          reinterpret_cast<unsigned int>(region),
-          reinterpret_cast<unsigned int>(masm),
-          masm->pc_offset(),
-          name);
+  LogMessageBuilder msg;
+  msg.Append("begin-code-region,0x%x,0x%x,0x%x,%s\n",
+             reinterpret_cast<unsigned int>(region),
+             reinterpret_cast<unsigned int>(masm),
+             masm->pc_offset(),
+             name);
+  msg.WriteToLogFile();
 #endif
 }
 
 
 void Logger::EndCodeRegionEvent(CodeRegion* region, Assembler* masm) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   if (logfile_ == NULL || !FLAG_log_code) return;
-  ScopedLock sl(mutex_);
-  fprintf(logfile_, "end-code-region,0x%x,0x%x,0x%x\n",
-          reinterpret_cast<unsigned int>(region),
-          reinterpret_cast<unsigned int>(masm),
-          masm->pc_offset());
+  LogMessageBuilder msg;
+  msg.Append("end-code-region,0x%x,0x%x,0x%x\n",
+             reinterpret_cast<unsigned int>(region),
+             reinterpret_cast<unsigned int>(masm),
+             masm->pc_offset());
+  msg.WriteToLogFile();
 #endif
 }
 
 
 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);
 
@@ skipping 161 matching lines @@
           }
         } else {
           stream.Put(*p);
         }
       }
       SmartPointer<const char> expanded = stream.ToCString();
       logfile_ = OS::FOpen(*expanded, "w");
     } else {
       logfile_ = OS::FOpen(FLAG_logfile, "w");
     }
+    message_buffer_ = NewArray<char>(kMessageBufferSize);
     mutex_ = OS::CreateMutex();
   }
 
   current_state_ = new VMState(OTHER);
 
   ticker_ = new Ticker(10);
 
   if (FLAG_sliding_state_window && sliding_state_window_ == NULL) {
     sliding_state_window_ = new SlidingStateWindow();
   }
@@ skipping 26 matching lines @@
   while (current_state_) delete current_state_;
   delete sliding_state_window_;
 
   delete ticker_;
 
   if (logfile_ != NULL) {
     fclose(logfile_);
     logfile_ = NULL;
     delete mutex_;
     mutex_ = NULL;
+    DeleteArray(message_buffer_);
   }
 #endif
 }
 
 
 void Logger::EnableSlidingStateWindow() {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   // If the ticker is NULL, Logger::Setup has not been called yet.  In
   // that case, we set the sliding_state_window flag so that the
   // sliding window computation will be started when Logger::Setup is
@@ skipping 53 matching lines @@
   if (FLAG_log_state_changes) {
     LOG(UncheckedStringEvent("Leaving", StateToString(state_)));
     if (previous_) {
       LOG(UncheckedStringEvent("To", StateToString(previous_->state_)));
     }
   }
 }
 #endif
 
 } }  // namespace v8::internal