Implement tagging of profiler log event blocks.

src/log.cc

 // Copyright 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
@@ skipping 312 matching lines @@
 // Logger class implementation.
 //
 Ticker* Logger::ticker_ = NULL;
 Profiler* Logger::profiler_ = NULL;
 VMState* Logger::current_state_ = NULL;
 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;
+int Logger::cpu_profiler_nesting_ = 0;
+int Logger::heap_profiler_nesting_ = 0;
 
 #define DECLARE_LONG_EVENT(ignore1, long_name, ignore2) long_name,
 const char* kLongLogEventsNames[Logger::NUMBER_OF_LOG_EVENTS] = {
   LOG_EVENTS_AND_TAGS_LIST(DECLARE_LONG_EVENT)
 };
 #undef DECLARE_LONG_EVENT
 
 #define DECLARE_SHORT_EVENT(ignore1, ignore2, short_name) short_name,
 const char* kCompressedLogEventsNames[Logger::NUMBER_OF_LOG_EVENTS] = {
   LOG_EVENTS_AND_TAGS_LIST(DECLARE_SHORT_EVENT)
@@ skipping 814 matching lines @@
   if (!profiler_->paused()) {
     result |= PROFILER_MODULE_CPU;
   }
   if (FLAG_log_gc) {
     result |= PROFILER_MODULE_HEAP_STATS | PROFILER_MODULE_JS_CONSTRUCTORS;
   }
   return result;
 }
 
 
-void Logger::PauseProfiler(int flags) {
+void Logger::PauseProfiler(int flags, int tag) {
   if (!Log::IsEnabled()) return;
-  const int active_modules = GetActiveProfilerModules();
-  const int modules_to_disable = active_modules & flags;
-  if (modules_to_disable == PROFILER_MODULE_NONE) return;
-
-  if (modules_to_disable & PROFILER_MODULE_CPU) {
-    profiler_->pause();
-    if (FLAG_prof_lazy) {
-      if (!FLAG_sliding_state_window) ticker_->Stop();
-      FLAG_log_code = false;
-      // Must be the same message as Log::kDynamicBufferSeal.
-      LOG(UncheckedStringEvent("profiler", "pause"));
+  if (flags & PROFILER_MODULE_CPU) {
+    if (--cpu_profiler_nesting_ == 0) {

[Søren Thygesen Gjesse, 2010/02/17 13:18:26]

Maybe make a note that these counters can be both positive and negative.

[mnaganov (inactive), 2010/02/17 13:22:50]

Done.

+      profiler_->pause();
+      if (FLAG_prof_lazy) {
+        if (!FLAG_sliding_state_window) ticker_->Stop();
+        FLAG_log_code = false;
+        // Must be the same message as Log::kDynamicBufferSeal.
+        LOG(UncheckedStringEvent("profiler", "pause"));
+      }
     }
   }
-  if (modules_to_disable &
+  if (flags &
       (PROFILER_MODULE_HEAP_STATS | PROFILER_MODULE_JS_CONSTRUCTORS)) {
-    FLAG_log_gc = false;
+    if (--heap_profiler_nesting_ == 0) {
+      FLAG_log_gc = false;
+    }
   }
-  // Turn off logging if no active modules remain.
-  if ((active_modules & ~flags) == PROFILER_MODULE_NONE) {
+  if (tag != 0) {
+    IntEvent("close-tag", tag);
+  }
+  if (GetActiveProfilerModules() == PROFILER_MODULE_NONE) {
     is_logging_ = false;
   }
 }
 
 
-void Logger::ResumeProfiler(int flags) {
+void Logger::ResumeProfiler(int flags, int tag) {
   if (!Log::IsEnabled()) return;
-  const int modules_to_enable = ~GetActiveProfilerModules() & flags;
-  if (modules_to_enable != PROFILER_MODULE_NONE) {
-    is_logging_ = true;
+  if (tag != 0) {
+    IntEvent("open-tag", tag);
   }
-  if (modules_to_enable & PROFILER_MODULE_CPU) {
-    if (FLAG_prof_lazy) {
-      profiler_->Engage();
-      LOG(UncheckedStringEvent("profiler", "resume"));
-      FLAG_log_code = true;
-      LogCompiledFunctions();
-      LogFunctionObjects();
-      LogAccessorCallbacks();
-      if (!FLAG_sliding_state_window) ticker_->Start();
+  if (flags & PROFILER_MODULE_CPU) {
+    if (cpu_profiler_nesting_++ == 0) {
+      is_logging_ = true;
+      if (FLAG_prof_lazy) {
+        profiler_->Engage();
+        LOG(UncheckedStringEvent("profiler", "resume"));
+        FLAG_log_code = true;
+        LogCompiledFunctions();
+        LogFunctionObjects();
+        LogAccessorCallbacks();
+        if (!FLAG_sliding_state_window) ticker_->Start();
+      }
+      profiler_->resume();
     }
-    profiler_->resume();
   }
-  if (modules_to_enable &
+  if (flags &
       (PROFILER_MODULE_HEAP_STATS | PROFILER_MODULE_JS_CONSTRUCTORS)) {
-    FLAG_log_gc = true;
+    if (heap_profiler_nesting_++ == 0) {
+      is_logging_ = true;
+      FLAG_log_gc = true;
+    }
   }
 }
 
 
 // This function can be called when Log's mutex is acquired,
 // either from main or Profiler's thread.
 void Logger::StopLoggingAndProfiling() {
   Log::stop();
-  PauseProfiler(PROFILER_MODULE_CPU);
+  PauseProfiler(PROFILER_MODULE_CPU, 0);
 }
 
 
 bool Logger::IsProfilerSamplerActive() {
   return ticker_->IsActive();
 }
 
 
 int Logger::GetLogLines(int from_pos, char* dest_buf, int max_size) {
   return Log::GetLogLines(from_pos, dest_buf, max_size);
@@ skipping 310 matching lines @@
   // Otherwise, if the sliding state window computation has not been
   // started we do it now.
   if (sliding_state_window_ == NULL) {
     sliding_state_window_ = new SlidingStateWindow();
   }
 #endif
 }
 
 
 } }  // namespace v8::internal