Add parallel recompilation time to histogram and plot execution pause times.

src/log.cc

 // Copyright 2011 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 513 matching lines @@
     cpu_profiler_nesting_(0),
     log_(new Log(this)),
     name_buffer_(new NameBuffer),
     address_to_name_map_(NULL),
     is_initialized_(false),
     code_event_handler_(NULL),
     last_address_(NULL),
     prev_sp_(NULL),
     prev_function_(NULL),
     prev_to_(NULL),
-    prev_code_(NULL) {
+    prev_code_(NULL),
+    epoch_(0) {
 }
 
 
 Logger::~Logger() {
   delete address_to_name_map_;
   delete name_buffer_;
   delete log_;
 }
 
 
@@ skipping 152 matching lines @@
   if (!log_->IsEnabled() || !FLAG_prof) return;
   LogMessageBuilder msg(this);
   msg.Append("shared-library,\"%ls\",0x%08" V8PRIxPTR ",0x%08" V8PRIxPTR "\n",
              library_path,
              start,
              end);
   msg.WriteToLogFile();
 }
 
 
+void Logger::TimerEvent(const char* name, int64_t start, int64_t end) {
+  ASSERT(FLAG_log_timer_events);
+  LogMessageBuilder msg(this);
+  int since_epoch = static_cast<int>(start - epoch_);
+  int pause_time = static_cast<int>(end - start);
+  msg.Append("timer-event,\"%s\",%ld,%ld\n", name, since_epoch, pause_time);
+  msg.WriteToLogFile();
+}
+
+
+const char* Logger::TimerEventScope::v8_recompile_synchronous =
+    "V8.RecompileSynchronous";
+const char* Logger::TimerEventScope::v8_recompile_parallel =
+    "V8.RecompileParallel";
+const char* Logger::TimerEventScope::v8_compile_full_code =
+    "V8.CompileFullCode";
+const char* Logger::TimerEventScope::v8_execute = "V8.Execute";
+
+
 void Logger::LogRegExpSource(Handle<JSRegExp> regexp) {
   // Prints "/" + re.source + "/" +
   //      (re.global?"g":"") + (re.ignorecase?"i":"") + (re.multiline?"m":"")
   LogMessageBuilder msg(this);
 
   Handle<Object> source = GetProperty(regexp, "source");
   if (!source->IsString()) {
     msg.Append("no source");
     return;
   }
@@ skipping 1003 matching lines @@
 
   Isolate* isolate = Isolate::Current();
   ticker_ = new Ticker(isolate, kSamplingIntervalMs);
 
   if (FLAG_sliding_state_window && sliding_state_window_ == NULL) {
     sliding_state_window_ = new SlidingStateWindow(isolate);
   }
 
   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_ll_prof;
+    || FLAG_log_regexp || FLAG_log_state_changes || FLAG_ll_prof
+    || FLAG_log_timer_events;
 
   if (start_logging) {
     logging_nesting_ = 1;
   }
 
   if (FLAG_prof) {
     profiler_ = new Profiler(isolate);
     if (!FLAG_prof_auto) {
       profiler_->pause();
     } else {
       logging_nesting_ = 1;
     }
     if (!FLAG_prof_lazy) {
       profiler_->Engage();
     }
   }
 
+  if (FLAG_log_timer_events) epoch_ = OS::Ticks();
+
   return true;
 }
 
 
 void Logger::SetCodeEventHandler(uint32_t options,
                                  JitCodeEventHandler event_handler) {
   code_event_handler_ = event_handler;
 
   if (code_event_handler_ != NULL && (options & kJitCodeEventEnumExisting)) {
     HandleScope scope;
@@ skipping 110 matching lines @@
 void SamplerRegistry::RemoveActiveSampler(Sampler* sampler) {
   ASSERT(sampler->IsActive());
   ScopedLock lock(active_samplers_mutex);
   ASSERT(active_samplers_ != NULL);
   bool removed = active_samplers_->RemoveElement(sampler);
   ASSERT(removed);
   USE(removed);
 }
 
 } }  // namespace v8::internal