Make logger use new sampling API for ticks and code events.

src/log.cc

 // Copyright 2011 the V8 project authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include <stdarg.h>
 
 #include "src/v8.h"
 
 #include "src/base/platform/platform.h"
 #include "src/bootstrapper.h"
@@ skipping 185 matching lines @@
   name_buffer_->AppendByte(' ');
   if (source->IsString()) {
     name_buffer_->AppendString(String::cast(source));
   } else {
     name_buffer_->AppendBytes("symbol(hash ");
     name_buffer_->AppendHex(Name::cast(source)->Hash());
     name_buffer_->AppendByte(')');
   }
   name_buffer_->AppendByte(':');
   name_buffer_->AppendInt(line);
+  name_buffer_->AppendByte(':');
+  name_buffer_->AppendInt(column);
   LogRecordedBuffer(code, shared, name_buffer_->get(), name_buffer_->size());
 }
 
 
 void CodeEventLogger::CodeCreateEvent(Logger::LogEventsAndTags tag,
                                       Code* code,
                                       int args_count) {
   name_buffer_->Init(tag);
   name_buffer_->AppendInt(args_count);
   LogRecordedBuffer(code, NULL, name_buffer_->get(), name_buffer_->size());
@@ skipping 716 matching lines @@
     ticker_(NULL),
     profiler_(NULL),
     log_events_(NULL),
     is_logging_(false),
     log_(new Log(this)),
     perf_basic_logger_(NULL),
     perf_jit_logger_(NULL),
     ll_logger_(NULL),
     jit_logger_(NULL),
     listeners_(5),
+    sampler_thread_(NULL),
     is_initialized_(false) {
 }
 
 
 Logger::~Logger() {
   delete log_;
 }
 
 
 void Logger::addCodeEventListener(CodeEventListener* listener) {
@@ skipping 370 matching lines @@
   CallbackEventInternal("get ", name, entry_point);
 }
 
 
 void Logger::SetterCallbackEvent(Name* name, Address entry_point) {
   PROFILER_LOG(SetterCallbackEvent(name, entry_point));
   CallbackEventInternal("set ", name, entry_point);
 }
 
 
-static void AppendCodeCreateHeader(Log::MessageBuilder* msg,
-                                   Logger::LogEventsAndTags tag,
-                                   Code* code) {
-  ASSERT(msg);
-  msg->Append("%s,%s,%d,",
-              kLogEventsNames[Logger::CODE_CREATION_EVENT],
-              kLogEventsNames[tag],
-              code->kind());
-  msg->AppendAddress(code->address());
-  msg->Append(",%d,", code->ExecutableSize());
+void Logger::CodeCreateEvent(const v8::JitCodeEvent* event) {
+  if (!is_logging_code_events() ||
+      !FLAG_log_code ||
+      !log_->IsEnabled()) return;
+
+  Log::MessageBuilder msg(log_);
+  msg.Append("%s,", kLogEventsNames[Logger::CODE_CREATION_EVENT]);
+
+  // Extract the tag name.
+  unsigned i = 0;
+  for (; i < event->name.len; i++) {
+    if (event->name.str[i] == ':') break;
+    msg.Append(event->name.str[i]);
+  }
+  i++;
+
+  msg.Append(",,%p,%d,\"", event->code_start, event->code_len);
+
+  // Have a look at function ComputeMarker
+  // The first character here might be the marker.
+  // In that case, get rid of that.
+  if ((i < event->name.len) &&
+      ((event->name.str[i] == '~') ||
+       (event->name.str[i] == '*')))
+    i++;
+
+  for (; i < event->name.len; i++) {
+    msg.Append(event->name.str[i]);
+  }
+  msg.Append("\"\n");
+
+  msg.WriteToLogFile();
 }
 
 
 void Logger::CodeCreateEvent(LogEventsAndTags tag,
                              Code* code,
                              const char* comment) {
   PROFILER_LOG(CodeCreateEvent(tag, code, comment));
 
   if (!is_logging_code_events()) return;
   CALL_LISTENERS(CodeCreateEvent(tag, code, comment));
-
-  if (!FLAG_log_code || !log_->IsEnabled()) return;
-  Log::MessageBuilder msg(log_);
-  AppendCodeCreateHeader(&msg, tag, code);
-  msg.AppendDoubleQuotedString(comment);
-  msg.Append('\n');
-  msg.WriteToLogFile();
 }
 
 
 void Logger::CodeCreateEvent(LogEventsAndTags tag,
                              Code* code,
                              Name* name) {
   PROFILER_LOG(CodeCreateEvent(tag, code, name));
 
   if (!is_logging_code_events()) return;
   CALL_LISTENERS(CodeCreateEvent(tag, code, name));
-
-  if (!FLAG_log_code || !log_->IsEnabled()) return;
-  Log::MessageBuilder msg(log_);
-  AppendCodeCreateHeader(&msg, tag, code);
-  if (name->IsString()) {
-    msg.Append('"');
-    msg.AppendDetailed(String::cast(name), false);
-    msg.Append('"');
-  } else {
-    msg.AppendSymbolName(Symbol::cast(name));
-  }
-  msg.Append('\n');
-  msg.WriteToLogFile();
 }
 
 
 void Logger::CodeCreateEvent(LogEventsAndTags tag,
                              Code* code,
                              SharedFunctionInfo* shared,
                              CompilationInfo* info,
                              Name* name) {
   PROFILER_LOG(CodeCreateEvent(tag, code, shared, info, name));
 
   if (!is_logging_code_events()) return;
   CALL_LISTENERS(CodeCreateEvent(tag, code, shared, info, name));
-
-  if (!FLAG_log_code || !log_->IsEnabled()) return;
-  if (code == isolate_->builtins()->builtin(Builtins::kCompileUnoptimized))
-    return;
-
-  Log::MessageBuilder msg(log_);
-  AppendCodeCreateHeader(&msg, tag, code);
-  if (name->IsString()) {
-    SmartArrayPointer<char> str =
-        String::cast(name)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
-    msg.Append("\"%s\"", str.get());
-  } else {
-    msg.AppendSymbolName(Symbol::cast(name));
-  }
-  msg.Append(',');
-  msg.AppendAddress(shared->address());
-  msg.Append(",%s", ComputeMarker(code));
-  msg.Append('\n');
-  msg.WriteToLogFile();
 }
 
 
 // Although, it is possible to extract source and line from
 // the SharedFunctionInfo object, we left it to caller
 // to leave logging functions free from heap allocations.
 void Logger::CodeCreateEvent(LogEventsAndTags tag,
                              Code* code,
                              SharedFunctionInfo* shared,
                              CompilationInfo* info,
                              Name* source, int line, int column) {
   PROFILER_LOG(CodeCreateEvent(tag, code, shared, info, source, line, column));
 
   if (!is_logging_code_events()) return;
   CALL_LISTENERS(CodeCreateEvent(tag, code, shared, info, source, line,
                                  column));
-
-  if (!FLAG_log_code || !log_->IsEnabled()) return;
-  Log::MessageBuilder msg(log_);
-  AppendCodeCreateHeader(&msg, tag, code);
-  SmartArrayPointer<char> name =
-      shared->DebugName()->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
-  msg.Append("\"%s ", name.get());
-  if (source->IsString()) {
-    SmartArrayPointer<char> sourcestr =
-       String::cast(source)->ToCString(DISALLOW_NULLS, ROBUST_STRING_TRAVERSAL);
-    msg.Append("%s", sourcestr.get());
-  } else {
-    msg.AppendSymbolName(Symbol::cast(source));
-  }
-  msg.Append(":%d:%d\",", line, column);
-  msg.AppendAddress(shared->address());
-  msg.Append(",%s", ComputeMarker(code));
-  msg.Append('\n');
-  msg.WriteToLogFile();
 }
 
 
 void Logger::CodeCreateEvent(LogEventsAndTags tag,
                              Code* code,
                              int args_count) {
   PROFILER_LOG(CodeCreateEvent(tag, code, args_count));
 
   if (!is_logging_code_events()) return;
   CALL_LISTENERS(CodeCreateEvent(tag, code, args_count));
-
-  if (!FLAG_log_code || !log_->IsEnabled()) return;
-  Log::MessageBuilder msg(log_);
-  AppendCodeCreateHeader(&msg, tag, code);
-  msg.Append("\"args_count: %d\"", args_count);
-  msg.Append('\n');
-  msg.WriteToLogFile();
 }
 
 
 void Logger::CodeDisableOptEvent(Code* code,
                                  SharedFunctionInfo* shared) {
   PROFILER_LOG(CodeDisableOptEvent(code, shared));
 
   if (!is_logging_code_events()) return;
   CALL_LISTENERS(CodeDisableOptEvent(code, shared));
 
@@ skipping 16 matching lines @@
   CALL_LISTENERS(CodeMovingGCEvent());
   base::OS::SignalCodeMovingGC();
 }
 
 
 void Logger::RegExpCodeCreateEvent(Code* code, String* source) {
   PROFILER_LOG(RegExpCodeCreateEvent(code, source));
 
   if (!is_logging_code_events()) return;
   CALL_LISTENERS(RegExpCodeCreateEvent(code, source));
-
-  if (!FLAG_log_code || !log_->IsEnabled()) return;
-  Log::MessageBuilder msg(log_);
-  AppendCodeCreateHeader(&msg, REG_EXP_TAG, code);
-  msg.Append('"');
-  msg.AppendDetailed(source, false);
-  msg.Append('"');
-  msg.Append('\n');
-  msg.WriteToLogFile();
 }
 
 
+void Logger::CodeMoveEvent(const v8::JitCodeEvent* event) {
+  if (!is_logging_code_events()) return;
+  MoveEventInternal(CODE_MOVE_EVENT,
+                    static_cast<Address>(event->code_start),
+                    static_cast<Address>(event->new_code_start));
+}
+
+
 void Logger::CodeMoveEvent(Address from, Address to) {
   PROFILER_LOG(CodeMoveEvent(from, to));
 
   if (!is_logging_code_events()) return;
   CALL_LISTENERS(CodeMoveEvent(from, to));
-  MoveEventInternal(CODE_MOVE_EVENT, from, to);
+}
+
+
+void Logger::CodeDeleteEvent(const v8::JitCodeEvent* event) {
+  if (!is_logging_code_events()) return;
+  if (!FLAG_log_code || !log_->IsEnabled()) return;
+  Log::MessageBuilder msg(log_);
+  msg.Append("%s,", kLogEventsNames[CODE_DELETE_EVENT]);
+  msg.AppendAddress(static_cast<Address>(event->code_start));
+  msg.Append('\n');
+  msg.WriteToLogFile();
 }
 
 
 void Logger::CodeDeleteEvent(Address from) {
   PROFILER_LOG(CodeDeleteEvent(from));
 
   if (!is_logging_code_events()) return;
   CALL_LISTENERS(CodeDeleteEvent(from));
-
-  if (!FLAG_log_code || !log_->IsEnabled()) return;
-  Log::MessageBuilder msg(log_);
-  msg.Append("%s,", kLogEventsNames[CODE_DELETE_EVENT]);
-  msg.AppendAddress(from);
-  msg.Append('\n');
-  msg.WriteToLogFile();
 }
 
 
 void Logger::CodeLinePosInfoAddPositionEvent(void* jit_handler_data,
                                      int pc_offset,
                                      int position) {
   JIT_LOG(AddCodeLinePosInfoEvent(jit_handler_data,
                                   pc_offset,
                                   position,
                                   JitCodeEvent::POSITION));
@@ skipping 150 matching lines @@
   Log::MessageBuilder msg(log_);
   msg.Append("debug-queue-event,%s,%15.3f,%s\n",
              event_type,
              base::OS::TimeCurrentMillis(),
              parameter_string);
   DeleteArray(parameter_string);
   msg.WriteToLogFile();
 }
 
 
-void Logger::TickEvent(TickSample* sample, bool overflow) {
+void Logger::LogSample(v8::Sample* sample) {
   if (!log_->IsEnabled() || !FLAG_prof) return;
+
   Log::MessageBuilder msg(log_);
-  msg.Append("%s,", kLogEventsNames[TICK_EVENT]);
-  msg.AppendAddress(sample->pc);
-  msg.Append(",%ld", static_cast<int>(timer_.Elapsed().InMicroseconds()));
-  if (sample->has_external_callback) {
-    msg.Append(",1,");
-    msg.AppendAddress(sample->external_callback);
-  } else {
-    msg.Append(",0,");
-    msg.AppendAddress(sample->tos);
-  }
-  msg.Append(",%d", static_cast<int>(sample->state));
-  if (overflow) {
-    msg.Append(",overflow");
-  }
+  msg.Append("%s,,%ld,,,",
+             kLogEventsNames[TICK_EVENT],
+             static_cast<int>(timer_.Elapsed().InMicroseconds()));
   for (unsigned i = 0; i < sample->frames_count; ++i) {
     msg.Append(',');
     msg.AppendAddress(static_cast<Address>(sample->stack[i]));
   }
   msg.Append('\n');
   msg.WriteToLogFile();
 }
 
 
 void Logger::StopProfiler() {
@@ skipping 320 matching lines @@
   ticker_ = new Ticker(isolate, kSamplingIntervalMs);
 
   if (Log::InitLogAtStart()) {
     is_logging_ = true;
   }
 
   if (FLAG_prof) {
     profiler_ = new Profiler(isolate);
     is_logging_ = true;
     profiler_->Engage();
+
+    sampler_thread_ = new SamplerThread(
+      reinterpret_cast<v8::Isolate*>(isolate));
   }
 
   // TODO(gholap): This one's for the new sampler API. (include/v8-sampler.h)
   //               Call to IncreaseProfilingDepth causes the
   //               SIGPROF signal handler to be installed on the VM thread.
   //               Figure out whether there's a way to only optionally
   //               do this based on a runtime flag.
   ticker_->IncreaseProfilingDepth();
 
   if (FLAG_log_internal_timer_events || FLAG_prof) timer_.Start();
@@ skipping 58 matching lines @@
     delete ll_logger_;
     ll_logger_ = NULL;
   }
 
   if (jit_logger_) {
     removeCodeEventListener(jit_logger_);
     delete jit_logger_;
     jit_logger_ = NULL;
   }
 
+  if (sampler_thread_) {
+    delete sampler_thread_;
+    sampler_thread_ = NULL;
+  }
+
   return log_->Close();
 }
 
+
+void Logger::SamplerThread::JitCodeEventHandler(const v8::JitCodeEvent* event) {
+  switch (event->type) {
+  case v8::JitCodeEvent::CODE_ADDED:
+    Isolate::Current()->logger()->CodeCreateEvent(event);
+    break;
+
+  case v8::JitCodeEvent::CODE_MOVED:
+    Isolate::Current()->logger()->CodeMoveEvent(event);
+    break;
+
+  case v8::JitCodeEvent::CODE_REMOVED:
+    Isolate::Current()->logger()->CodeDeleteEvent(event);
+    break;
+
+  default:
+    break;
+  }
+}
+
+
+Logger::SamplerThread::SamplerThread(v8::Isolate* isolate)
+    : Thread(Thread::Options("d8:sampler")),
+      isolate_(isolate),
+      done_sampling_(false) {
+  reinterpret_cast<Isolate*>(isolate)->logger()->SetCodeEventHandler(
+    v8::kJitCodeEventDefault,
+    Logger::SamplerThread::JitCodeEventHandler);
+  Start();
+}
+
+
+void Logger::SamplerThread::Run() {
+  Sample sample;
+  while (!done_sampling_) {
+    v8::base::OS::Sleep(1);
+    isolate_->GetSample(&sample);
+    if (sample.frames_count != 0) {
+      reinterpret_cast<Isolate*>(isolate_)->logger()->LogSample(&sample);
+    }
+  }
+}
+
+
+Logger::SamplerThread::~SamplerThread() {
+  done_sampling_ = true;
+  Join();
+}
+
 } }  // namespace v8::internal