Attempt to reduce performance penalty for logging and profiling

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

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

src/codegen.cc

@@ -225,7 +225,7 @@ Handle<Code> CodeGenerator::MakeCode(FunctionLiteral* flit,
 
 bool CodeGenerator::ShouldGenerateLog(Expression* type) {
   ASSERT(type != NULL);
-  if (!Logger::IsEnabled()) return false;
+  if (!Logger::is_logging()) return false;
   Handle<String> name = Handle<String>::cast(type->AsLiteral()->handle());
   if (FLAG_log_regexp) {
     static Vector<const char> kRegexp = CStrVector("regexp");

src/compiler.cc

@@ -175,7 +175,7 @@ static Handle<JSFunction> MakeFunction(bool is_global,
 #if defined ENABLE_LOGGING_AND_PROFILING || defined ENABLE_OPROFILE_AGENT
   // Log the code generation for the script. Check explicit whether logging is
   // to avoid allocating when not required.
-  if (Logger::IsEnabled() || OProfileAgent::is_enabled()) {
+  if (Logger::is_logging() || OProfileAgent::is_enabled()) {
     if (script->name()->IsString()) {
       SmartPointer<char> data =
           String::cast(script->name())->ToCString(DISALLOW_NULLS);
@@ -373,7 +373,7 @@ bool Compiler::CompileLazy(Handle<SharedFunctionInfo> shared,
   // Log the code generation. If source information is available include script
   // name and line number. Check explicit whether logging is enabled as finding
   // the line number is not for free.
-  if (Logger::IsEnabled() || OProfileAgent::is_enabled()) {
+  if (Logger::is_logging() || OProfileAgent::is_enabled()) {
     Handle<String> func_name(name->length() > 0 ?
                              *name : shared->inferred_name());
     if (script->name()->IsString()) {

src/log-inl.h

+// Copyright 2006-2009 the V8 project authors. All rights reserved.
+// Redistribution and use in source and binary forms, with or without
+// modification, are permitted provided that the following conditions are
+// met:
+//
+//     * Redistributions of source code must retain the above copyright
+//       notice, this list of conditions and the following disclaimer.
+//     * Redistributions in binary form must reproduce the above
+//       copyright notice, this list of conditions and the following
+//       disclaimer in the documentation and/or other materials provided
+//       with the distribution.
+//     * Neither the name of Google Inc. nor the names of its
+//       contributors may be used to endorse or promote products derived
+//       from this software without specific prior written permission.
+//
+// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
+// "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
+// LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
+// A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
+// OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+// SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+// LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
+// DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
+// THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
+// (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
+// OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+
+#ifndef V8_LOG_INL_H_
+#define V8_LOG_INL_H_
+
+#include "log.h"
+
+namespace v8 {
+namespace internal {
+
+//
+// VMState class implementation.  A simple stack of VM states held by the
+// logger and partially threaded through the call stack.  States are pushed by
+// VMState construction and popped by destruction.
+//
+#ifdef ENABLE_LOGGING_AND_PROFILING
+inline const char* StateToString(StateTag state) {
+  switch (state) {
+    case JS:
+      return "JS";
+    case GC:
+      return "GC";
+    case COMPILER:
+      return "COMPILER";
+    case OTHER:
+      return "OTHER";
+    default:
+      UNREACHABLE();
+      return NULL;
+  }
+}
+
+VMState::VMState(StateTag state) : disabled_(true) {
+  if (!Logger::is_logging()) {
+    return;
+  }
+
+  disabled_ = false;
+#if !defined(ENABLE_HEAP_PROTECTION)
+  // When not protecting the heap, there is no difference between
+  // EXTERNAL and OTHER.  As an optimization in that case, we will not
+  // perform EXTERNAL->OTHER transitions through the API.  We thus
+  // compress the two states into one.
+  if (state == EXTERNAL) state = OTHER;
+#endif
+  state_ = state;
+  previous_ = Logger::current_state_;
+  Logger::current_state_ = this;
+
+  if (FLAG_log_state_changes) {
+    LOG(UncheckedStringEvent("Entering", StateToString(state_)));
+    if (previous_ != NULL) {
+      LOG(UncheckedStringEvent("From", StateToString(previous_->state_)));
+    }
+  }
+
+#ifdef ENABLE_HEAP_PROTECTION
+  if (FLAG_protect_heap && previous_ != NULL) {
+    if (state_ == EXTERNAL) {
+      // We are leaving V8.
+      ASSERT(previous_->state_ != EXTERNAL);
+      Heap::Protect();
+    } else if (previous_->state_ == EXTERNAL) {
+      // We are entering V8.
+      Heap::Unprotect();
+    }
+  }
+#endif
+}
+
+
+VMState::~VMState() {
+  if (disabled_) return;
+  Logger::current_state_ = previous_;
+
+  if (FLAG_log_state_changes) {
+    LOG(UncheckedStringEvent("Leaving", StateToString(state_)));
+    if (previous_ != NULL) {
+      LOG(UncheckedStringEvent("To", StateToString(previous_->state_)));
+    }
+  }
+
+#ifdef ENABLE_HEAP_PROTECTION
+  if (FLAG_protect_heap && previous_ != NULL) {
+    if (state_ == EXTERNAL) {
+      // We are reentering V8.
+      ASSERT(previous_->state_ != EXTERNAL);
+      Heap::Unprotect();
+    } else if (previous_->state_ == EXTERNAL) {
+      // We are leaving V8.
+      Heap::Protect();
+    }
+  }
+#endif
+}
+#endif
+
+
+} }  // namespace v8::internal
+
+#endif  // V8_LOG_INL_H_

src/log.cc

@@ -31,9 +31,7 @@
 
 #include "bootstrapper.h"
 #include "log.h"
-#include "log-utils.h"
 #include "macro-assembler.h"
-#include "platform.h"
 #include "serialize.h"
 #include "string-stream.h"
 
@@ -304,6 +302,7 @@ VMState Logger::bottom_state_(EXTERNAL);
 SlidingStateWindow* Logger::sliding_state_window_ = NULL;
 const char** Logger::log_events_ = NULL;
 CompressionHelper* Logger::compression_helper_ = NULL;
+bool Logger::is_logging_ = false;
 
 #define DECLARE_LONG_EVENT(ignore1, long_name, ignore2) long_name,
 const char* kLongLogEventsNames[Logger::NUMBER_OF_LOG_EVENTS] = {
@@ -318,11 +317,6 @@ const char* kCompressedLogEventsNames[Logger::NUMBER_OF_LOG_EVENTS] = {
 #undef DECLARE_SHORT_EVENT
 
 
-bool Logger::IsEnabled() {
-  return Log::IsEnabled();
-}
-
-
 void Logger::ProfilerBeginEvent() {
   if (!Log::IsEnabled()) return;
   LogMessageBuilder msg;
@@ -946,6 +940,7 @@ void Logger::PauseProfiler() {
     // Must be the same message as Log::kDynamicBufferSeal.
     LOG(UncheckedStringEvent("profiler", "pause"));
   }
+  is_logging_ = false;
 }
 
 
@@ -953,6 +948,7 @@ void Logger::ResumeProfiler() {
   if (!profiler_->paused() || !Log::IsEnabled()) {
     return;
   }
+  is_logging_ = true;
   if (FLAG_prof_lazy) {
     LOG(UncheckedStringEvent("profiler", "resume"));
     FLAG_log_code = true;
@@ -1069,9 +1065,11 @@ bool Logger::Setup() {
     FLAG_prof_auto = false;
   }
 
-  bool open_log_file = FLAG_log || FLAG_log_runtime || FLAG_log_api
+  bool start_logging = 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 || FLAG_prof_lazy;
+      || FLAG_log_regexp || FLAG_log_state_changes;
+
+  bool open_log_file = start_logging || FLAG_prof_lazy;
 
   // If we're logging anything, we need to open the log file.
   if (open_log_file) {
@@ -1134,10 +1132,15 @@ bool Logger::Setup() {
     compression_helper_ = new CompressionHelper(kCompressionWindowSize);
   }
 
+  is_logging_ = start_logging;
+
   if (FLAG_prof) {
     profiler_ = new Profiler();
-    if (!FLAG_prof_auto)
+    if (!FLAG_prof_auto) {
       profiler_->pause();
+    } else {
+      is_logging_ = true;
+    }
     profiler_->Engage();
   }
 
@@ -1195,85 +1198,4 @@ void Logger::EnableSlidingStateWindow() {
 }
 
 
-//
-// VMState class implementation.  A simple stack of VM states held by the
-// logger and partially threaded through the call stack.  States are pushed by
-// VMState construction and popped by destruction.
-//
-#ifdef ENABLE_LOGGING_AND_PROFILING
-static const char* StateToString(StateTag state) {
-  switch (state) {
-    case JS:
-      return "JS";
-    case GC:
-      return "GC";
-    case COMPILER:
-      return "COMPILER";
-    case OTHER:
-      return "OTHER";
-    default:
-      UNREACHABLE();
-      return NULL;
-  }
-}
-
-VMState::VMState(StateTag state) {
-#if !defined(ENABLE_HEAP_PROTECTION)
-  // When not protecting the heap, there is no difference between
-  // EXTERNAL and OTHER.  As an optimization in that case, we will not
-  // perform EXTERNAL->OTHER transitions through the API.  We thus
-  // compress the two states into one.
-  if (state == EXTERNAL) state = OTHER;
-#endif
-  state_ = state;
-  previous_ = Logger::current_state_;
-  Logger::current_state_ = this;
-
-  if (FLAG_log_state_changes) {
-    LOG(UncheckedStringEvent("Entering", StateToString(state_)));
-    if (previous_ != NULL) {
-      LOG(UncheckedStringEvent("From", StateToString(previous_->state_)));
-    }
-  }
-
-#ifdef ENABLE_HEAP_PROTECTION
-  if (FLAG_protect_heap && previous_ != NULL) {
-    if (state_ == EXTERNAL) {
-      // We are leaving V8.
-      ASSERT(previous_->state_ != EXTERNAL);
-      Heap::Protect();
-    } else if (previous_->state_ == EXTERNAL) {
-      // We are entering V8.
-      Heap::Unprotect();
-    }
-  }
-#endif
-}
-
-
-VMState::~VMState() {
-  Logger::current_state_ = previous_;
-
-  if (FLAG_log_state_changes) {
-    LOG(UncheckedStringEvent("Leaving", StateToString(state_)));
-    if (previous_ != NULL) {
-      LOG(UncheckedStringEvent("To", StateToString(previous_->state_)));
-    }
-  }
-
-#ifdef ENABLE_HEAP_PROTECTION
-  if (FLAG_protect_heap && previous_ != NULL) {
-    if (state_ == EXTERNAL) {
-      // We are reentering V8.
-      ASSERT(previous_->state_ != EXTERNAL);
-      Heap::Unprotect();
-    } else if (previous_->state_ == EXTERNAL) {
-      // We are leaving V8.
-      Heap::Protect();
-    }
-  }
-#endif
-}
-#endif
-
 } }  // namespace v8::internal

src/log.h

@@ -28,6 +28,9 @@
 #ifndef V8_LOG_H_
 #define V8_LOG_H_
 
+#include "platform.h"
+#include "log-utils.h"
+
 namespace v8 {
 namespace internal {
 
@@ -77,7 +80,7 @@ class CompressionHelper;
 #ifdef ENABLE_LOGGING_AND_PROFILING
 #define LOG(Call)                           \
   do {                                      \
-    if (v8::internal::Logger::IsEnabled()) \
+    if (v8::internal::Logger::is_logging()) \
       v8::internal::Logger::Call;           \
   } while (false)
 #else
@@ -88,12 +91,13 @@ class CompressionHelper;
 class VMState BASE_EMBEDDED {
 #ifdef ENABLE_LOGGING_AND_PROFILING
  public:
-  explicit VMState(StateTag state);
-  ~VMState();
+  inline explicit VMState(StateTag state);
+  inline ~VMState();
 
   StateTag state() { return state_; }
 
  private:
+  bool disabled_;
   StateTag state_;
   VMState* previous_;
 #else
@@ -236,7 +240,9 @@ class Logger {
     return current_state_ ? current_state_->state() : OTHER;
   }
 
-  static bool IsEnabled();
+  static bool is_logging() {
+    return is_logging_;
+  }
 
   // Pause/Resume collection of profiling data.
   // When data collection is paused, Tick events are discarded until
@@ -317,8 +323,10 @@ class Logger {
   friend class VMState;
 
   friend class LoggerTestHelper;
+
+  static bool is_logging_;
 #else
-  static bool is_enabled() { return false; }
+  static bool is_logging() { return false; }
 #endif
 };
 

src/platform.h

@@ -109,6 +109,8 @@ int random();
 namespace v8 {
 namespace internal {
 
+class Semaphore;
+
 double ceiling(double x);
 
 // Forward declarations.

src/v8.h

@@ -71,6 +71,7 @@
 #include "objects-inl.h"
 #include "spaces-inl.h"
 #include "heap-inl.h"
+#include "log-inl.h"
 #include "messages.h"
 
 namespace v8 {

tools/gyp/v8.gyp

@@ -164,6 +164,7 @@
       '../../src/list-inl.h',
       '../../src/list.h',
       '../../src/log.cc',
+      '../../src/log-inl.h',
       '../../src/log.h',
       '../../src/log-utils.cc',
       '../../src/log-utils.h',

tools/v8.xcodeproj/project.pbxproj

@@ -273,6 +273,7 @@
 /* End PBXContainerItemProxy section */
 
 /* Begin PBXFileReference section */
+		22A76C900FF259E600FDC694 /* log-inl.h */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.c.h; path = "log-inl.h"; sourceTree = "<group>"; };
 		58242A1E0FA1F14D00BD6F59 /* json-delay.js */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.javascript; path = "json-delay.js"; sourceTree = "<group>"; };
 		58950D4E0F55514900F3E8BA /* jump-target-arm.cc */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.cpp.cpp; name = "jump-target-arm.cc"; path = "arm/jump-target-arm.cc"; sourceTree = "<group>"; };
 		58950D4F0F55514900F3E8BA /* jump-target-ia32.cc */ = {isa = PBXFileReference; fileEncoding = 4; lastKnownFileType = sourcecode.cpp.cpp; name = "jump-target-ia32.cc"; path = "ia32/jump-target-ia32.cc"; sourceTree = "<group>"; };
@@ -622,6 +623,7 @@
 		897FF0D70E719AB300D62E90 /* C++ */ = {
 			isa = PBXGroup;
 			children = (
+				22A76C900FF259E600FDC694 /* log-inl.h */,
 				897FF0F60E719B8F00D62E90 /* accessors.cc */,
 				897FF0F70E719B8F00D62E90 /* accessors.h */,
 				897FF0F80E719B8F00D62E90 /* allocation.cc */,

tools/visual_studio/v8_base.vcproj

@@ -540,6 +540,10 @@
 				RelativePath="..\..\src\log.cc"
 				>
 			</File>
+			<File
+				RelativePath="..\..\src\log-inl.h"
+				>
+			</File>
 			<File
 				RelativePath="..\..\src\log.h"
 				>

tools/visual_studio/v8_base_arm.vcproj

@@ -536,6 +536,10 @@
 				RelativePath="..\..\src\log.cc"
 				>
 			</File>
+			<File
+				RelativePath="..\..\src\log-inl.h"
+				>
+			</File>
 			<File
 				RelativePath="..\..\src\log.h"
 				>