Introduce internal Log class that handles writing log messages, enable logging to...
authormikhail.naganov@gmail.com <mikhail.naganov@gmail.com@ce2b1a6d-e550-0410-aec6-3dcde31c8c00>
Tue, 5 May 2009 15:57:47 +0000 (15:57 +0000)
committermikhail.naganov@gmail.com <mikhail.naganov@gmail.com@ce2b1a6d-e550-0410-aec6-3dcde31c8c00>
Tue, 5 May 2009 15:57:47 +0000 (15:57 +0000)
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
src/api.cc
src/log.cc
src/log.h
test/cctest/SConscript
test/cctest/test-log.cc [new file with mode: 0644]
tools/visual_studio/v8_cctest.vcproj
tools/visual_studio/v8_cctest_arm.vcproj

index 6d1826126bd357ebc7555da00421cbc012babfc6..2e5d679c18418a95ce44c3733fb87c95f900c0a5 100644 (file)
@@ -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
index 59eed300ffd7df27cc784ea82ddc142f61451364..a811a29ad013605098cd6e14d67e6eada02b2cbe 100644 (file)
@@ -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()");
index 4d4dfa70e5f47a61e8f92fa558c5665862ef3c7c..8a2fbb7dcbd05cf4cc6519735b15717e6ba7e5c1 100644 (file)
@@ -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
 }
 
index 44c1957697c7220942dce041ddba90d60cce8adf..a7c6604a178d2106e52325f326ec623a402870d6 100644 (file)
--- a/src/log.h
+++ b/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;
index eb94fc5897c95dcbd25ac743b8fafe11efe2159a..740acbaa68c213b1c9f46a776709f9f911639044 100644 (file)
@@ -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',
diff --git a/test/cctest/test-log.cc b/test/cctest/test-log.cc
new file mode 100644 (file)
index 0000000..0370cbe
--- /dev/null
@@ -0,0 +1,102 @@
+// 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
index 29023f8fc9633a6d3042730a0aa75d173f052759..6aa090ad0b3654d654edd3cc9e1289bb0f4a264a 100644 (file)
                        RelativePath="..\..\test\cctest\test-lock.cc"
                        >
                </File>
+               <File
+                       RelativePath="..\..\test\cctest\test-log.cc"
+                       >
+               </File>
                <File
                        RelativePath="..\..\test\cctest\test-log-ia32.cc"
                        >
index 44ffbc71ff41970c92db2f006dee564044eb952f..566d75eef36b5b315b4b95a0e0328dc83cb07b92 100644 (file)
                        RelativePath="..\..\test\cctest\test-lock.cc"
                        >
                </File>
+               <File
+                       RelativePath="..\..\test\cctest\test-log.cc"
+                       >
+               </File>
                <File
                        RelativePath="..\..\test\cctest\test-mark-compact.cc"
                        >