Introduce internal Log class that handles writing log messages, enable logging to memory buffer.

This will enable reading profiler log in Chrome. The current implementation of memory buffer is trivial (fixed size buffer, no memory recycling) but enough to start end-to-end DevTools Profiler implementation. Later it will be enhanced.

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

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

include/v8.h

@@ -1126,9 +1126,9 @@ class V8EXPORT Object : public Value {
 
   /**
    * Returns the identity hash for this object. The current implemenation uses
-   * a hidden property on the object to store the identity hash. 
+   * a hidden property on the object to store the identity hash.
    *
-   * The return value will never be 0. Also, it is not guaranteed to be 
+   * The return value will never be 0. Also, it is not guaranteed to be
    * unique.
    */
   int GetIdentityHash();
@@ -2079,6 +2079,24 @@ class V8EXPORT V8 {
    */
   static void ResumeProfiler();
 
+  /**
+   * If logging is performed into a memory buffer (via --logfile=*), allows to
+   * retrieve previously written messages. This can be used for retrieving
+   * profiler log data in the application. This function is thread-safe.
+   *
+   * Caller provides a destination buffer that must exist during GetLogLines
+   * call. Only whole log lines are copied into the buffer.
+   *
+   * \param from_pos specified a point in a buffer to read from, 0 is the
+   *   beginning of a buffer. It is assumed that caller updates its current
+   *   position using returned size value from the previous call.
+   * \param dest_buf destination buffer for log data.
+   * \param max_size size of the destination buffer.
+   * \returns actual size of log data copied into buffer.
+   */
+  static int GetLogLines(int from_pos, char* dest_buf, int max_size);
+
+
   /**
    * Releases any resources used by v8 and stops any utility threads
    * that may be running.  Note that disposing v8 is permanent, it

src/api.cc

@@ -3112,6 +3112,11 @@ void V8::ResumeProfiler() {
 #endif
 }
 
+int V8::GetLogLines(int from_pos, char* dest_buf, int max_size) {
+#ifdef ENABLE_LOGGING_AND_PROFILING
+  return i::Logger::GetLogLines(from_pos, dest_buf, max_size);
+#endif
+}
 
 String::Utf8Value::Utf8Value(v8::Handle<v8::Value> obj) {
   EnsureInitialized("v8::String::Utf8Value::Utf8Value()");

src/log.cc

@@ -285,8 +285,178 @@ void Profiler::Run() {
 
 
 #ifdef ENABLE_LOGGING_AND_PROFILING
+
+// Functions and data for performing output of log messages.
+class Log : public AllStatic {
+ public:
+  // Opens stdout for logging.
+  static void OpenStdout();
+
+  // Opens file for logging.
+  static void OpenFile(const char* name);
+
+  // Opens memory buffer for logging.
+  static void OpenMemoryBuffer();
+
+  // Frees all resources acquired in Open... functions.
+  static void Close();
+
+  // See description in v8.h.
+  static int GetLogLines(int from_pos, char* dest_buf, int max_size);
+
+  static bool is_enabled() { return output_.handle != NULL; }
+
+  typedef int (*WritePtr)(const char* msg, int length);
+ private:
+  static void Init();
+
+  // Write functions assume that mutex_ is acquired by the caller.
+  static WritePtr Write;
+
+  static int WriteToFile(const char* msg, int length) {
+    ASSERT(output_.handle != NULL);
+    int rv = fwrite(msg, 1, length, output_.handle);
+    ASSERT(length == rv);
+    return rv;
+  }
+
+  static int WriteToMemory(const char* msg, int length) {
+    ASSERT(output_.buffer != NULL);
+    ASSERT(output_buffer_write_pos_ >= output_.buffer);
+    if (output_buffer_write_pos_ + length
+        <= output_.buffer + kOutputBufferSize) {
+      memcpy(output_buffer_write_pos_, msg, length);
+      output_buffer_write_pos_ += length;
+      return length;
+    } else {
+      // Memory buffer is full, ignore write.
+      return 0;
+    }
+  }
+
+  // When logging is active, output_ refers the file or memory buffer
+  // events are written to.
+  // mutex_ should be acquired before using output_.
+  union Output {
+    FILE* handle;
+    char* buffer;
+  };
+  static Output output_;
+
+  // mutex_ is a Mutex used for enforcing exclusive
+  // access to the formatting buffer and the log file or log memory buffer.
+  static Mutex* mutex_;
+
+  // Size of buffer used for memory logging.
+  static const int kOutputBufferSize = 2 * 1024 * 1024;
+
+  // Writing position in a memory buffer.
+  static char* output_buffer_write_pos_;
+
+  // Size of buffer used for formatting log messages.
+  static const int kMessageBufferSize = 2048;
+
+  // Buffer used for formatting log messages. This is a singleton buffer and
+  // mutex_ should be acquired before using it.
+  static char* message_buffer_;
+
+  friend class LogMessageBuilder;
+};
+
+
+Log::WritePtr Log::Write = NULL;
+Log::Output Log::output_ = {NULL};
+Mutex* Log::mutex_ = NULL;
+char* Log::output_buffer_write_pos_ = NULL;
+char* Log::message_buffer_ = NULL;
+
+
+void Log::Init() {
+  mutex_ = OS::CreateMutex();
+  message_buffer_ = NewArray<char>(kMessageBufferSize);
+}
+
+
+void Log::OpenStdout() {
+  ASSERT(output_.handle == NULL);
+  output_.handle = stdout;
+  Write = WriteToFile;
+  Init();
+}
+
+
+void Log::OpenFile(const char* name) {
+  ASSERT(output_.handle == NULL);
+  output_.handle = OS::FOpen(name, OS::LogFileOpenMode);
+  Write = WriteToFile;
+  Init();
+}
+
+
+void Log::OpenMemoryBuffer() {
+  ASSERT(output_.buffer == NULL);
+  output_.buffer = NewArray<char>(kOutputBufferSize);
+  output_buffer_write_pos_ = output_.buffer;
+  Write = WriteToMemory;
+  Init();
+}
+
+
+void Log::Close() {
+  if (Write == WriteToFile) {
+    fclose(output_.handle);
+    output_.handle = NULL;
+  } else if (Write == WriteToMemory) {
+    DeleteArray(output_.buffer);
+    output_.buffer = NULL;
+  } else {
+    ASSERT(Write == NULL);
+  }
+  Write = NULL;
+
+  delete mutex_;
+  mutex_ = NULL;
+
+  DeleteArray(message_buffer_);
+  message_buffer_ = NULL;
+}
+
+
+int Log::GetLogLines(int from_pos, char* dest_buf, int max_size) {
+  ASSERT(output_.buffer != NULL);
+  ASSERT(output_buffer_write_pos_ >= output_.buffer);
+  ASSERT(from_pos >= 0);
+  ASSERT(max_size >= 0);
+  int actual_size = max_size;
+  char* buffer_read_pos = output_.buffer + from_pos;
+  ScopedLock sl(mutex_);
+  if (actual_size == 0
+      || output_buffer_write_pos_ == output_.buffer
+      || buffer_read_pos >= output_buffer_write_pos_) {
+    // No data requested or can be returned.
+    return 0;
+  }
+  if (buffer_read_pos + actual_size > output_buffer_write_pos_) {
+    // Requested size overlaps with current writing position and
+    // needs to be truncated.
+    actual_size = output_buffer_write_pos_ - buffer_read_pos;
+    ASSERT(actual_size == 0 || buffer_read_pos[actual_size - 1] == '\n');
+  } else {
+    // Find previous log line boundary.
+    char* end_pos = buffer_read_pos + actual_size - 1;
+    while (end_pos >= buffer_read_pos && *end_pos != '\n') --end_pos;
+    actual_size = end_pos - buffer_read_pos + 1;
+  }
+  ASSERT(actual_size <= max_size);
+  if (actual_size > 0) {
+    memcpy(dest_buf, buffer_read_pos, actual_size);
+  }
+  return actual_size;
+}
+
+
 // Utility class for formatting log messages. It fills the message into the
-// static buffer in Logger.
+// static buffer in Log.
 class LogMessageBuilder BASE_EMBEDDED {
  public:
   explicit LogMessageBuilder();
@@ -309,45 +479,45 @@ class LogMessageBuilder BASE_EMBEDDED {
 
 // Create a message builder starting from position 0. This acquires the mutex
 // in the logger as well.
-LogMessageBuilder::LogMessageBuilder(): sl(Logger::mutex_), pos_(0) {
-  ASSERT(Logger::message_buffer_ != NULL);
+LogMessageBuilder::LogMessageBuilder(): sl(Log::mutex_), pos_(0) {
+  ASSERT(Log::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_);
+  Vector<char> buf(Log::message_buffer_ + pos_,
+                   Log::kMessageBufferSize - pos_);
   va_list args;
   va_start(args, format);
   Append(format, args);
   va_end(args);
-  ASSERT(pos_ <= Logger::kMessageBufferSize);
+  ASSERT(pos_ <= Log::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_);
+  Vector<char> buf(Log::message_buffer_ + pos_,
+                   Log::kMessageBufferSize - pos_);
   int result = v8::internal::OS::VSNPrintF(buf, format, args);
 
   // Result is -1 if output was truncated.
   if (result >= 0) {
     pos_ += result;
   } else {
-    pos_ = Logger::kMessageBufferSize;
+    pos_ = Log::kMessageBufferSize;
   }
-  ASSERT(pos_ <= Logger::kMessageBufferSize);
+  ASSERT(pos_ <= Log::kMessageBufferSize);
 }
 
 
 // Append a character to the log message.
 void LogMessageBuilder::Append(const char c) {
-  if (pos_ < Logger::kMessageBufferSize) {
-    Logger::message_buffer_[pos_++] = c;
+  if (pos_ < Log::kMessageBufferSize) {
+    Log::message_buffer_[pos_++] = c;
   }
-  ASSERT(pos_ <= Logger::kMessageBufferSize);
+  ASSERT(pos_ <= Log::kMessageBufferSize);
 }
 
 
@@ -391,18 +561,14 @@ void LogMessageBuilder::AppendDetailed(String* str, bool show_impl_info) {
 
 // Write the log message to the log file currently opened.
 void LogMessageBuilder::WriteToLogFile() {
-  ASSERT(pos_ <= Logger::kMessageBufferSize);
-  size_t rv = fwrite(Logger::message_buffer_, 1, pos_, Logger::logfile_);
-  ASSERT(rv == static_cast<size_t>(pos_));
-  USE(rv);
+  ASSERT(pos_ <= Log::kMessageBufferSize);
+  Log::Write(Log::message_buffer_, pos_);
 }
 
 // Write a null-terminated string to to the log file currently opened.
 void LogMessageBuilder::WriteCStringToLogFile(const char* str) {
-  size_t len = strlen(str);
-  size_t rv = fwrite(str, 1, len, Logger::logfile_);
-  ASSERT(rv == len);
-  USE(rv);
+  int len = strlen(str);
+  Log::Write(str, len);
 }
 #endif
 
@@ -411,20 +577,22 @@ void LogMessageBuilder::WriteCStringToLogFile(const char* str) {
 // 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;
 VMState Logger::bottom_state_(EXTERNAL);
 SlidingStateWindow* Logger::sliding_state_window_ = NULL;
 
+
+bool Logger::is_enabled() {
+  return Log::is_enabled();
+}
+
 #endif  // ENABLE_LOGGING_AND_PROFILING
 
 
 void Logger::Preamble(const char* content) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_code) return;
+  if (!Log::is_enabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
   msg.WriteCStringToLogFile(content);
 #endif
@@ -440,7 +608,7 @@ void Logger::StringEvent(const char* name, const char* value) {
 
 #ifdef ENABLE_LOGGING_AND_PROFILING
 void Logger::UncheckedStringEvent(const char* name, const char* value) {
-  if (logfile_ == NULL) return;
+  if (!Log::is_enabled()) return;
   LogMessageBuilder msg;
   msg.Append("%s,\"%s\"\n", name, value);
   msg.WriteToLogFile();
@@ -450,7 +618,7 @@ void Logger::UncheckedStringEvent(const char* name, const char* value) {
 
 void Logger::IntEvent(const char* name, int value) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log) return;
+  if (!Log::is_enabled() || !FLAG_log) return;
   LogMessageBuilder msg;
   msg.Append("%s,%d\n", name, value);
   msg.WriteToLogFile();
@@ -460,7 +628,7 @@ void Logger::IntEvent(const char* name, int value) {
 
 void Logger::HandleEvent(const char* name, Object** location) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_handles) return;
+  if (!Log::is_enabled() || !FLAG_log_handles) return;
   LogMessageBuilder msg;
   msg.Append("%s,0x%x\n", name,
              reinterpret_cast<unsigned int>(location));
@@ -471,10 +639,10 @@ void Logger::HandleEvent(const char* name, Object** location) {
 
 #ifdef ENABLE_LOGGING_AND_PROFILING
 // ApiEvent is private so all the calls come from the Logger class.  It is the
-// caller's responsibility to ensure that logfile_ is not NULL and that
+// caller's responsibility to ensure that log is enabled and that
 // FLAG_log_api is true.
 void Logger::ApiEvent(const char* format, ...) {
-  ASSERT(logfile_ != NULL && FLAG_log_api);
+  ASSERT(Log::is_enabled() && FLAG_log_api);
   LogMessageBuilder msg;
   va_list ap;
   va_start(ap, format);
@@ -487,7 +655,7 @@ void Logger::ApiEvent(const char* format, ...) {
 
 void Logger::ApiNamedSecurityCheck(Object* key) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_api) return;
+  if (!Log::is_enabled() || !FLAG_log_api) return;
   if (key->IsString()) {
     SmartPointer<char> str =
         String::cast(key)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
@@ -505,7 +673,7 @@ void Logger::SharedLibraryEvent(const char* library_path,
                                 unsigned start,
                                 unsigned end) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_prof) return;
+  if (!Log::is_enabled() || !FLAG_prof) return;
   LogMessageBuilder msg;
   msg.Append("shared-library,\"%s\",0x%08x,0x%08x\n", library_path,
              start, end);
@@ -518,7 +686,7 @@ void Logger::SharedLibraryEvent(const wchar_t* library_path,
                                 unsigned start,
                                 unsigned end) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_prof) return;
+  if (!Log::is_enabled() || !FLAG_prof) return;
   LogMessageBuilder msg;
   msg.Append("shared-library,\"%ls\",0x%08x,0x%08x\n", library_path,
              start, end);
@@ -573,7 +741,7 @@ void Logger::LogRegExpSource(Handle<JSRegExp> regexp) {
 
 void Logger::RegExpCompileEvent(Handle<JSRegExp> regexp, bool in_cache) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_regexp) return;
+  if (!Log::is_enabled() || !FLAG_log_regexp) return;
   LogMessageBuilder msg;
   msg.Append("regexp-compile,");
   LogRegExpSource(regexp);
@@ -585,7 +753,7 @@ void Logger::RegExpCompileEvent(Handle<JSRegExp> regexp, bool in_cache) {
 
 void Logger::LogRuntime(Vector<const char> format, JSArray* args) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_runtime) return;
+  if (!Log::is_enabled() || !FLAG_log_runtime) return;
   HandleScope scope;
   LogMessageBuilder msg;
   for (int i = 0; i < format.length(); i++) {
@@ -626,7 +794,7 @@ void Logger::LogRuntime(Vector<const char> format, JSArray* args) {
 
 void Logger::ApiIndexedSecurityCheck(uint32_t index) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_api) return;
+  if (!Log::is_enabled() || !FLAG_log_api) return;
   ApiEvent("api,check-security,%u\n", index);
 #endif
 }
@@ -637,7 +805,7 @@ void Logger::ApiNamedPropertyAccess(const char* tag,
                                     Object* name) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
   ASSERT(name->IsString());
-  if (logfile_ == NULL || !FLAG_log_api) return;
+  if (!Log::is_enabled() || !FLAG_log_api) return;
   String* class_name_obj = holder->class_name();
   SmartPointer<char> class_name =
       class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
@@ -651,7 +819,7 @@ void Logger::ApiIndexedPropertyAccess(const char* tag,
                                       JSObject* holder,
                                       uint32_t index) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_api) return;
+  if (!Log::is_enabled() || !FLAG_log_api) return;
   String* class_name_obj = holder->class_name();
   SmartPointer<char> class_name =
       class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
@@ -661,7 +829,7 @@ void Logger::ApiIndexedPropertyAccess(const char* tag,
 
 void Logger::ApiObjectAccess(const char* tag, JSObject* object) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_api) return;
+  if (!Log::is_enabled() || !FLAG_log_api) return;
   String* class_name_obj = object->class_name();
   SmartPointer<char> class_name =
       class_name_obj->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
@@ -672,7 +840,7 @@ void Logger::ApiObjectAccess(const char* tag, JSObject* object) {
 
 void Logger::ApiEntryCall(const char* name) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_api) return;
+  if (!Log::is_enabled() || !FLAG_log_api) return;
   Logger::ApiEvent("api,%s\n", name);
 #endif
 }
@@ -680,7 +848,7 @@ void Logger::ApiEntryCall(const char* name) {
 
 void Logger::NewEvent(const char* name, void* object, size_t size) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log) return;
+  if (!Log::is_enabled() || !FLAG_log) return;
   LogMessageBuilder msg;
   msg.Append("new,%s,0x%x,%u\n", name,
              reinterpret_cast<unsigned int>(object),
@@ -692,7 +860,7 @@ void Logger::NewEvent(const char* name, void* object, size_t size) {
 
 void Logger::DeleteEvent(const char* name, void* object) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log) return;
+  if (!Log::is_enabled() || !FLAG_log) return;
   LogMessageBuilder msg;
   msg.Append("delete,%s,0x%x\n", name,
              reinterpret_cast<unsigned int>(object));
@@ -703,7 +871,7 @@ void Logger::DeleteEvent(const char* name, void* object) {
 
 void Logger::CodeCreateEvent(const char* tag, Code* code, const char* comment) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_code) return;
+  if (!Log::is_enabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
   msg.Append("code-creation,%s,0x%x,%d,\"", tag,
              reinterpret_cast<unsigned int>(code->address()),
@@ -723,7 +891,7 @@ void Logger::CodeCreateEvent(const char* tag, Code* code, const char* comment) {
 
 void Logger::CodeCreateEvent(const char* tag, Code* code, String* name) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_code) return;
+  if (!Log::is_enabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
   SmartPointer<char> str =
       name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
@@ -738,7 +906,7 @@ void Logger::CodeCreateEvent(const char* tag, Code* code, String* name) {
 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;
+  if (!Log::is_enabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
   SmartPointer<char> str =
       name->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
@@ -755,7 +923,7 @@ void Logger::CodeCreateEvent(const char* tag, Code* code, String* name,
 
 void Logger::CodeCreateEvent(const char* tag, Code* code, int args_count) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_code) return;
+  if (!Log::is_enabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
   msg.Append("code-creation,%s,0x%x,%d,\"args_count: %d\"\n", tag,
              reinterpret_cast<unsigned int>(code->address()),
@@ -768,7 +936,7 @@ void Logger::CodeCreateEvent(const char* tag, Code* code, int args_count) {
 
 void Logger::RegExpCodeCreateEvent(Code* code, String* source) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_code) return;
+  if (!Log::is_enabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
   msg.Append("code-creation,%s,0x%x,%d,\"", "RegExp",
              reinterpret_cast<unsigned int>(code->address()),
@@ -782,7 +950,7 @@ void Logger::RegExpCodeCreateEvent(Code* code, String* source) {
 
 void Logger::CodeAllocateEvent(Code* code, Assembler* assem) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_code) return;
+  if (!Log::is_enabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
   msg.Append("code-allocate,0x%x,0x%x\n",
              reinterpret_cast<unsigned int>(code->address()),
@@ -794,7 +962,7 @@ void Logger::CodeAllocateEvent(Code* code, Assembler* assem) {
 
 void Logger::CodeMoveEvent(Address from, Address to) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_code) return;
+  if (!Log::is_enabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
   msg.Append("code-move,0x%x,0x%x\n",
              reinterpret_cast<unsigned int>(from),
@@ -806,7 +974,7 @@ void Logger::CodeMoveEvent(Address from, Address to) {
 
 void Logger::CodeDeleteEvent(Address from) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_code) return;
+  if (!Log::is_enabled() || !FLAG_log_code) return;
   LogMessageBuilder msg;
   msg.Append("code-delete,0x%x\n", reinterpret_cast<unsigned int>(from));
   msg.WriteToLogFile();
@@ -816,7 +984,7 @@ void Logger::CodeDeleteEvent(Address from) {
 
 void Logger::ResourceEvent(const char* name, const char* tag) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log) return;
+  if (!Log::is_enabled() || !FLAG_log) return;
   LogMessageBuilder msg;
   msg.Append("%s,%s,", name, tag);
 
@@ -834,12 +1002,11 @@ void Logger::ResourceEvent(const char* name, const char* tag) {
 
 void Logger::SuspectReadEvent(String* name, Object* obj) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_suspect) return;
+  if (!Log::is_enabled() || !FLAG_log_suspect) return;
   LogMessageBuilder msg;
   String* class_name = obj->IsJSObject()
                        ? JSObject::cast(obj)->class_name()
                        : Heap::empty_string();
-  ScopedLock sl(mutex_);
   msg.Append("suspect-read,");
   msg.Append(class_name);
   msg.Append(',');
@@ -854,7 +1021,7 @@ void Logger::SuspectReadEvent(String* name, Object* obj) {
 
 void Logger::HeapSampleBeginEvent(const char* space, const char* kind) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_gc) return;
+  if (!Log::is_enabled() || !FLAG_log_gc) return;
   LogMessageBuilder msg;
   msg.Append("heap-sample-begin,\"%s\",\"%s\"\n", space, kind);
   msg.WriteToLogFile();
@@ -864,7 +1031,7 @@ void Logger::HeapSampleBeginEvent(const char* space, const char* kind) {
 
 void Logger::HeapSampleEndEvent(const char* space, const char* kind) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_gc) return;
+  if (!Log::is_enabled() || !FLAG_log_gc) return;
   LogMessageBuilder msg;
   msg.Append("heap-sample-end,\"%s\",\"%s\"\n", space, kind);
   msg.WriteToLogFile();
@@ -874,7 +1041,7 @@ void Logger::HeapSampleEndEvent(const char* space, const char* kind) {
 
 void Logger::HeapSampleItemEvent(const char* type, int number, int bytes) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log_gc) return;
+  if (!Log::is_enabled() || !FLAG_log_gc) return;
   LogMessageBuilder msg;
   msg.Append("heap-sample-item,%s,%d,%d\n", type, number, bytes);
   msg.WriteToLogFile();
@@ -884,7 +1051,7 @@ void Logger::HeapSampleItemEvent(const char* type, int number, int bytes) {
 
 void Logger::DebugTag(const char* call_site_tag) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log) return;
+  if (!Log::is_enabled() || !FLAG_log) return;
   LogMessageBuilder msg;
   msg.Append("debug-tag,%s\n", call_site_tag);
   msg.WriteToLogFile();
@@ -894,7 +1061,7 @@ void Logger::DebugTag(const char* call_site_tag) {
 
 void Logger::DebugEvent(const char* event_type, Vector<uint16_t> parameter) {
 #ifdef ENABLE_LOGGING_AND_PROFILING
-  if (logfile_ == NULL || !FLAG_log) return;
+  if (!Log::is_enabled() || !FLAG_log) return;
   StringBuilder s(parameter.length() + 1);
   for (int i = 0; i < parameter.length(); ++i) {
     s.AddCharacter(static_cast<char>(parameter[i]));
@@ -913,7 +1080,7 @@ void Logger::DebugEvent(const char* event_type, Vector<uint16_t> parameter) {
 
 #ifdef ENABLE_LOGGING_AND_PROFILING
 void Logger::TickEvent(TickSample* sample, bool overflow) {
-  if (logfile_ == NULL || !FLAG_prof) return;
+  if (!Log::is_enabled() || !FLAG_prof) return;
   LogMessageBuilder msg;
   msg.Append("tick,0x%x,0x%x,%d", sample->pc, sample->sp,
              static_cast<int>(sample->state));
@@ -941,6 +1108,12 @@ void Logger::PauseProfiler() {
 void Logger::ResumeProfiler() {
   profiler_->resume();
 }
+
+
+int Logger::GetLogLines(int from_pos, char* dest_buf, int max_size) {
+  return Log::GetLogLines(from_pos, dest_buf, max_size);
+}
+
 #endif
 
 
@@ -967,7 +1140,9 @@ bool Logger::Setup() {
   // If we're logging anything, we need to open the log file.
   if (open_log_file) {
     if (strcmp(FLAG_logfile, "-") == 0) {
-      logfile_ = stdout;
+      Log::OpenStdout();
+    } else if (strcmp(FLAG_logfile, "*") == 0) {
+      Log::OpenMemoryBuffer();
     } else if (strchr(FLAG_logfile, '%') != NULL) {
       // If there's a '%' in the log file name we have to expand
       // placeholders.
@@ -1003,12 +1178,10 @@ bool Logger::Setup() {
         }
       }
       SmartPointer<const char> expanded = stream.ToCString();
-      logfile_ = OS::FOpen(*expanded, OS::LogFileOpenMode);
+      Log::OpenFile(*expanded);
     } else {
-      logfile_ = OS::FOpen(FLAG_logfile, OS::LogFileOpenMode);
+      Log::OpenFile(FLAG_logfile);
     }
-    message_buffer_ = NewArray<char>(kMessageBufferSize);
-    mutex_ = OS::CreateMutex();
   }
 
   current_state_ = &bottom_state_;
@@ -1050,13 +1223,7 @@ void Logger::TearDown() {
 
   delete ticker_;
 
-  if (logfile_ != NULL) {
-    fclose(logfile_);
-    logfile_ = NULL;
-    delete mutex_;
-    mutex_ = NULL;
-    DeleteArray(message_buffer_);
-  }
+  Log::Close();
 #endif
 }
 

src/log.h

@@ -103,10 +103,10 @@ class VMState BASE_EMBEDDED {
 
 class Logger {
  public:
-  // Opens the file for logging if the right flags are set.
+  // Acquires resources for logging if the right flags are set.
   static bool Setup();
 
-  // Closes file opened in Setup.
+  // Frees resources acquired in Setup.
   static void TearDown();
 
   // Enable the computation of a sliding window of states.
@@ -201,7 +201,7 @@ class Logger {
     return current_state_ ? current_state_->state() : OTHER;
   }
 
-  static bool is_enabled() { return logfile_ != NULL; }
+  static bool is_enabled();
 
   // Pause/Resume collection of profiling data.
   // When data collection is paused, Tick events are discarded until
@@ -210,6 +210,10 @@ class Logger {
   static void PauseProfiler();
   static void ResumeProfiler();
 
+  // If logging is performed into a memory buffer, allows to
+  // retrieve previously written messages. See v8.h.
+  static int GetLogLines(int from_pos, char* dest_buf, int max_size);
+
  private:
 
   // Emits the source code of a regexp. Used by regexp events.
@@ -223,17 +227,6 @@ class Logger {
   // Logs a StringEvent regardless of whether FLAG_log is true.
   static void UncheckedStringEvent(const char* name, const char* value);
 
-  // Size of buffer used for formatting log messages.
-  static const int kMessageBufferSize = 2048;
-
-  // Buffer used for formatting log messages. This is a singleton buffer and
-  // mutex_ should be acquired before using it.
-  static char* message_buffer_;
-
-  // When logging is active, logfile_ refers the file events are written to.
-  // mutex_ should be acquired before using logfile_.
-  static FILE* logfile_;
-
   // The sampler used by the profiler and the sliding state window.
   static Ticker* ticker_;
 
@@ -242,10 +235,6 @@ class Logger {
   // of samples.
   static Profiler* profiler_;
 
-  // mutex_ is a Mutex used for enforcing exclusive
-  // access to the formatting buffer and the log file.
-  static Mutex* mutex_;
-
   // A stack of VM states.
   static VMState* current_state_;
 
@@ -258,7 +247,6 @@ class Logger {
 
   // Internal implementation classes with access to
   // private members.
-  friend class LogMessageBuilder;
   friend class EventLog;
   friend class TimeLog;
   friend class Profiler;

test/cctest/SConscript

@@ -47,6 +47,7 @@ SOURCES = {
     'test-heap.cc',
     'test-list.cc',
     'test-lock.cc',
+    'test-log.cc',
     'test-mark-compact.cc',
     'test-regexp.cc',
     'test-serialize.cc',

test/cctest/test-log.cc

+// Copyright 2006-2009 the V8 project authors. All rights reserved.
+//
+// Tests of logging functions from log.h
+
+#ifdef ENABLE_LOGGING_AND_PROFILING
+
+#include "v8.h"
+
+#include "log.h"
+
+#include "cctest.h"
+
+using v8::internal::Logger;
+
+static void SetUp() {
+  // Log to memory buffer.
+  v8::internal::FLAG_logfile = "*";
+  v8::internal::FLAG_log = true;
+  Logger::Setup();
+}
+
+static void TearDown() {
+  Logger::TearDown();
+}
+
+TEST(EmptyLog) {
+  SetUp();
+  CHECK_EQ(0, Logger::GetLogLines(0, NULL, 0));
+  CHECK_EQ(0, Logger::GetLogLines(100, NULL, 0));
+  CHECK_EQ(0, Logger::GetLogLines(0, NULL, 100));
+  CHECK_EQ(0, Logger::GetLogLines(100, NULL, 100));
+  TearDown();
+}
+
+
+TEST(GetMessages) {
+  SetUp();
+  Logger::StringEvent("aaa", "bbb");
+  Logger::StringEvent("cccc", "dddd");
+  CHECK_EQ(0, Logger::GetLogLines(0, NULL, 0));
+  char log_lines[100];
+  memset(log_lines, 0, sizeof(log_lines));
+  // Requesting data size which is smaller than first log message length.
+  CHECK_EQ(0, Logger::GetLogLines(0, log_lines, 3));
+  // See Logger::StringEvent.
+  const char* line_1 = "aaa,\"bbb\"\n";
+  const int line_1_len = strlen(line_1);
+  // Still smaller than log message length.
+  CHECK_EQ(0, Logger::GetLogLines(0, log_lines, line_1_len - 1));
+  // The exact size.
+  CHECK_EQ(line_1_len, Logger::GetLogLines(0, log_lines, line_1_len));
+  CHECK_EQ(line_1, log_lines);
+  memset(log_lines, 0, sizeof(log_lines));
+  // A bit more than the first line length.
+  CHECK_EQ(line_1_len, Logger::GetLogLines(0, log_lines, line_1_len + 3));
+  CHECK_EQ(line_1, log_lines);
+  memset(log_lines, 0, sizeof(log_lines));
+  const char* line_2 = "cccc,\"dddd\"\n";
+  const int line_2_len = strlen(line_2);
+  // Now start with line_2 beginning.
+  CHECK_EQ(0, Logger::GetLogLines(line_1_len, log_lines, 0));
+  CHECK_EQ(0, Logger::GetLogLines(line_1_len, log_lines, 3));
+  CHECK_EQ(0, Logger::GetLogLines(line_1_len, log_lines, line_2_len - 1));
+  CHECK_EQ(line_2_len, Logger::GetLogLines(line_1_len, log_lines, line_2_len));
+  CHECK_EQ(line_2, log_lines);
+  memset(log_lines, 0, sizeof(log_lines));
+  CHECK_EQ(line_2_len,
+           Logger::GetLogLines(line_1_len, log_lines, line_2_len + 3));
+  CHECK_EQ(line_2, log_lines);
+  memset(log_lines, 0, sizeof(log_lines));
+  // Now get entire buffer contents.
+  const char* all_lines = "aaa,\"bbb\"\ncccc,\"dddd\"\n";
+  const int all_lines_len = strlen(all_lines);
+  CHECK_EQ(all_lines_len, Logger::GetLogLines(0, log_lines, all_lines_len));
+  CHECK_EQ(all_lines, log_lines);
+  memset(log_lines, 0, sizeof(log_lines));
+  CHECK_EQ(all_lines_len, Logger::GetLogLines(0, log_lines, all_lines_len + 3));
+  CHECK_EQ(all_lines, log_lines);
+  memset(log_lines, 0, sizeof(log_lines));
+  TearDown();
+}
+
+
+TEST(BeyondWritePosition) {
+  SetUp();
+  Logger::StringEvent("aaa", "bbb");
+  Logger::StringEvent("cccc", "dddd");
+  // See Logger::StringEvent.
+  const char* all_lines = "aaa,\"bbb\"\ncccc,\"dddd\"\n";
+  const int all_lines_len = strlen(all_lines);
+  CHECK_EQ(0, Logger::GetLogLines(all_lines_len, NULL, 1));
+  CHECK_EQ(0, Logger::GetLogLines(all_lines_len, NULL, 100));
+  CHECK_EQ(0, Logger::GetLogLines(all_lines_len + 1, NULL, 1));
+  CHECK_EQ(0, Logger::GetLogLines(all_lines_len + 1, NULL, 100));
+  CHECK_EQ(0, Logger::GetLogLines(all_lines_len + 100, NULL, 1));
+  CHECK_EQ(0, Logger::GetLogLines(all_lines_len + 100, NULL, 100));
+  CHECK_EQ(0, Logger::GetLogLines(10 * 1024 * 1024, NULL, 1));
+  CHECK_EQ(0, Logger::GetLogLines(10 * 1024 * 1024, NULL, 100));
+  TearDown();
+}
+
+#endif  // ENABLE_LOGGING_AND_PROFILING

tools/visual_studio/v8_cctest.vcproj

@@ -201,6 +201,10 @@
 			RelativePath="..\..\test\cctest\test-lock.cc"
 			>
 		</File>
+		<File
+			RelativePath="..\..\test\cctest\test-log.cc"
+			>
+		</File>
 		<File
 			RelativePath="..\..\test\cctest\test-log-ia32.cc"
 			>

tools/visual_studio/v8_cctest_arm.vcproj

@@ -195,6 +195,10 @@
 			RelativePath="..\..\test\cctest\test-lock.cc"
 			>
 		</File>
+		<File
+			RelativePath="..\..\test\cctest\test-log.cc"
+			>
+		</File>
 		<File
 			RelativePath="..\..\test\cctest\test-mark-compact.cc"
 			>