Do not expose all timer events to the API callback.

R=fmeawad@chromium.org Review URL: https://codereview.chromium.org/388783004 git-svn-id: https://v8.googlecode.com/svn/branches/bleeding_edge@22422 ce2b1a6d-e550-0410-aec6-3dcde31c8c00
2014-07-16 08:14:50 +00:00 · 2014-07-16 08:14:50 +00:00 · 21a2f36b25
commit 21a2f36b25
parent 570ea3bf5d
9 changed files with 85 additions and 105 deletions
--- a/src/api.cc
+++ b/src/api.cc
@ -1675,8 +1675,7 @@ Local<Value> Script::Run() {
  ON_BAILOUT(isolate, "v8::Script::Run()", return Local<Value>());
  LOG_API(isolate, "Script::Run");
  ENTER_V8(isolate);
-  i::Logger::TimerEventScope timer_scope(
-      isolate, i::Logger::TimerEventScope::v8_execute);
+  i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate);
  i::HandleScope scope(isolate);
  i::Handle<i::JSFunction> fun = i::Handle<i::JSFunction>::cast(obj);
  EXCEPTION_PREAMBLE(isolate);
@ -3849,8 +3848,7 @@ Local<v8::Value> Object::CallAsFunction(v8::Handle<v8::Value> recv,
             return Local<v8::Value>());
  LOG_API(isolate, "Object::CallAsFunction");
  ENTER_V8(isolate);
-  i::Logger::TimerEventScope timer_scope(
-      isolate, i::Logger::TimerEventScope::v8_execute);
+  i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate);
  i::HandleScope scope(isolate);
  i::Handle<i::JSObject> obj = Utils::OpenHandle(this);
  i::Handle<i::Object> recv_obj = Utils::OpenHandle(*recv);
@ -3884,8 +3882,7 @@ Local<v8::Value> Object::CallAsConstructor(int argc,
             return Local<v8::Object>());
  LOG_API(isolate, "Object::CallAsConstructor");
  ENTER_V8(isolate);
-  i::Logger::TimerEventScope timer_scope(
-      isolate, i::Logger::TimerEventScope::v8_execute);
+  i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate);
  i::HandleScope scope(isolate);
  i::Handle<i::JSObject> obj = Utils::OpenHandle(this);
  STATIC_ASSERT(sizeof(v8::Handle<v8::Value>) == sizeof(i::Object**));
@ -3944,8 +3941,7 @@ Local<v8::Object> Function::NewInstance(int argc,
             return Local<v8::Object>());
  LOG_API(isolate, "Function::NewInstance");
  ENTER_V8(isolate);
-  i::Logger::TimerEventScope timer_scope(
-      isolate, i::Logger::TimerEventScope::v8_execute);
+  i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate);
  EscapableHandleScope scope(reinterpret_cast<Isolate*>(isolate));
  i::Handle<i::JSFunction> function = Utils::OpenHandle(this);
  STATIC_ASSERT(sizeof(v8::Handle<v8::Value>) == sizeof(i::Object**));
@ -3965,8 +3961,7 @@ Local<v8::Value> Function::Call(v8::Handle<v8::Value> recv, int argc,
  ON_BAILOUT(isolate, "v8::Function::Call()", return Local<v8::Value>());
  LOG_API(isolate, "Function::Call");
  ENTER_V8(isolate);
-  i::Logger::TimerEventScope timer_scope(
-      isolate, i::Logger::TimerEventScope::v8_execute);
+  i::TimerEventScope<i::TimerEventExecute> timer_scope(isolate);
  i::HandleScope scope(isolate);
  i::Handle<i::JSFunction> fun = Utils::OpenHandle(this);
  i::Handle<i::Object> recv_obj = Utils::OpenHandle(*recv);
--- a/src/compiler.cc
+++ b/src/compiler.cc
@ -1132,8 +1132,7 @@ static bool CompileOptimizedPrologue(CompilationInfo* info) {
 static bool GetOptimizedCodeNow(CompilationInfo* info) {
  if (!CompileOptimizedPrologue(info)) return false;

-  Logger::TimerEventScope timer(
-      info->isolate(), Logger::TimerEventScope::v8_recompile_synchronous);
+  TimerEventScope<TimerEventRecompileSynchronous> timer(info->isolate());

  OptimizedCompileJob job(info);
  if (job.CreateGraph() != OptimizedCompileJob::SUCCEEDED) return false;
@ -1164,8 +1163,7 @@ static bool GetOptimizedCodeLater(CompilationInfo* info) {
  if (!CompileOptimizedPrologue(info)) return false;
  info->SaveHandles();  // Copy handles to the compilation handle scope.

-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_recompile_synchronous);
+  TimerEventScope<TimerEventRecompileSynchronous> timer(info->isolate());

  OptimizedCompileJob* job = new(info->zone()) OptimizedCompileJob(info);
  OptimizedCompileJob::Status status = job->CreateGraph();
@ -1238,8 +1236,7 @@ Handle<Code> Compiler::GetConcurrentlyOptimizedCode(OptimizedCompileJob* job) {
  Isolate* isolate = info->isolate();

  VMState<COMPILER> state(isolate);
-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_recompile_synchronous);
+  TimerEventScope<TimerEventRecompileSynchronous> timer(info->isolate());

  Handle<SharedFunctionInfo> shared = info->shared_info();
  shared->code()->set_profiler_ticks(0);
--- a/src/full-codegen.cc
+++ b/src/full-codegen.cc
@ -290,8 +290,7 @@ void BreakableStatementChecker::VisitThisFunction(ThisFunction* expr) {
 bool FullCodeGenerator::MakeCode(CompilationInfo* info) {
  Isolate* isolate = info->isolate();

-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_compile_full_code);
+  TimerEventScope<TimerEventCompileFullCode> timer(info->isolate());

  Handle<Script> script = info->script();
  if (!script->IsUndefined() && !script->source()->IsUndefined()) {
--- a/src/ic.cc
+++ b/src/ic.cc
@ -1947,8 +1947,7 @@ void CallIC::HandleMiss(Handle<Object> receiver,

 // Used from ic-<arch>.cc.
 RUNTIME_FUNCTION(CallIC_Miss) {
-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_ic_miss);
+  TimerEventScope<TimerEventIcMiss> timer(isolate);
  HandleScope scope(isolate);
  ASSERT(args.length() == 4);
  CallIC ic(isolate);
@ -1962,8 +1961,7 @@ RUNTIME_FUNCTION(CallIC_Miss) {


 RUNTIME_FUNCTION(CallIC_Customization_Miss) {
-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_ic_miss);
+  TimerEventScope<TimerEventIcMiss> timer(isolate);
  HandleScope scope(isolate);
  ASSERT(args.length() == 4);
  // A miss on a custom call ic always results in going megamorphic.
@ -1978,8 +1976,7 @@ RUNTIME_FUNCTION(CallIC_Customization_Miss) {

 // Used from ic-<arch>.cc.
 RUNTIME_FUNCTION(LoadIC_Miss) {
-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_ic_miss);
+  TimerEventScope<TimerEventIcMiss> timer(isolate);
  HandleScope scope(isolate);
  ASSERT(args.length() == 2);
  LoadIC ic(IC::NO_EXTRA_FRAME, isolate);
@ -1994,8 +1991,7 @@ RUNTIME_FUNCTION(LoadIC_Miss) {

 // Used from ic-<arch>.cc
 RUNTIME_FUNCTION(KeyedLoadIC_Miss) {
-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_ic_miss);
+  TimerEventScope<TimerEventIcMiss> timer(isolate);
  HandleScope scope(isolate);
  ASSERT(args.length() == 2);
  KeyedLoadIC ic(IC::NO_EXTRA_FRAME, isolate);
@ -2009,8 +2005,7 @@ RUNTIME_FUNCTION(KeyedLoadIC_Miss) {


 RUNTIME_FUNCTION(KeyedLoadIC_MissFromStubFailure) {
-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_ic_miss);
+  TimerEventScope<TimerEventIcMiss> timer(isolate);
  HandleScope scope(isolate);
  ASSERT(args.length() == 2);
  KeyedLoadIC ic(IC::EXTRA_CALL_FRAME, isolate);
@ -2025,8 +2020,7 @@ RUNTIME_FUNCTION(KeyedLoadIC_MissFromStubFailure) {

 // Used from ic-<arch>.cc.
 RUNTIME_FUNCTION(StoreIC_Miss) {
-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_ic_miss);
+  TimerEventScope<TimerEventIcMiss> timer(isolate);
  HandleScope scope(isolate);
  ASSERT(args.length() == 3);
  StoreIC ic(IC::NO_EXTRA_FRAME, isolate);
@ -2043,8 +2037,7 @@ RUNTIME_FUNCTION(StoreIC_Miss) {


 RUNTIME_FUNCTION(StoreIC_MissFromStubFailure) {
-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_ic_miss);
+  TimerEventScope<TimerEventIcMiss> timer(isolate);
  HandleScope scope(isolate);
  ASSERT(args.length() == 3);
  StoreIC ic(IC::EXTRA_CALL_FRAME, isolate);
@ -2061,8 +2054,7 @@ RUNTIME_FUNCTION(StoreIC_MissFromStubFailure) {


 RUNTIME_FUNCTION(StoreIC_ArrayLength) {
-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_ic_miss);
+  TimerEventScope<TimerEventIcMiss> timer(isolate);
  HandleScope scope(isolate);

  ASSERT(args.length() == 2);
@ -2089,8 +2081,7 @@ RUNTIME_FUNCTION(StoreIC_ArrayLength) {
 // it is necessary to extend the properties array of a
 // JSObject.
 RUNTIME_FUNCTION(SharedStoreIC_ExtendStorage) {
-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_ic_miss);
+  TimerEventScope<TimerEventIcMiss> timer(isolate);
  HandleScope shs(isolate);
  ASSERT(args.length() == 3);

@ -2112,8 +2103,7 @@ RUNTIME_FUNCTION(SharedStoreIC_ExtendStorage) {

 // Used from ic-<arch>.cc.
 RUNTIME_FUNCTION(KeyedStoreIC_Miss) {
-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_ic_miss);
+  TimerEventScope<TimerEventIcMiss> timer(isolate);
  HandleScope scope(isolate);
  ASSERT(args.length() == 3);
  KeyedStoreIC ic(IC::NO_EXTRA_FRAME, isolate);
@ -2130,8 +2120,7 @@ RUNTIME_FUNCTION(KeyedStoreIC_Miss) {


 RUNTIME_FUNCTION(KeyedStoreIC_MissFromStubFailure) {
-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_ic_miss);
+  TimerEventScope<TimerEventIcMiss> timer(isolate);
  HandleScope scope(isolate);
  ASSERT(args.length() == 3);
  KeyedStoreIC ic(IC::EXTRA_CALL_FRAME, isolate);
@ -2182,8 +2171,7 @@ RUNTIME_FUNCTION(KeyedStoreIC_Slow) {


 RUNTIME_FUNCTION(ElementsTransitionAndStoreIC_Miss) {
-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_ic_miss);
+  TimerEventScope<TimerEventIcMiss> timer(isolate);
  HandleScope scope(isolate);
  ASSERT(args.length() == 4);
  KeyedStoreIC ic(IC::EXTRA_CALL_FRAME, isolate);
@ -2688,8 +2676,7 @@ MaybeHandle<Object> BinaryOpIC::Transition(


 RUNTIME_FUNCTION(BinaryOpIC_Miss) {
-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_ic_miss);
+  TimerEventScope<TimerEventIcMiss> timer(isolate);
  HandleScope scope(isolate);
  ASSERT_EQ(2, args.length());
  Handle<Object> left = args.at<Object>(BinaryOpICStub::kLeft);
@ -2705,8 +2692,7 @@ RUNTIME_FUNCTION(BinaryOpIC_Miss) {


 RUNTIME_FUNCTION(BinaryOpIC_MissWithAllocationSite) {
-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_ic_miss);
+  TimerEventScope<TimerEventIcMiss> timer(isolate);
  HandleScope scope(isolate);
  ASSERT_EQ(3, args.length());
  Handle<AllocationSite> allocation_site = args.at<AllocationSite>(
@ -2940,8 +2926,7 @@ Code* CompareIC::UpdateCaches(Handle<Object> x, Handle<Object> y) {

 // Used from ICCompareStub::GenerateMiss in code-stubs-<arch>.cc.
 RUNTIME_FUNCTION(CompareIC_Miss) {
-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_ic_miss);
+  TimerEventScope<TimerEventIcMiss> timer(isolate);
  HandleScope scope(isolate);
  ASSERT(args.length() == 3);
  CompareIC ic(isolate, static_cast<Token::Value>(args.smi_at(2)));
@ -3006,8 +2991,7 @@ Handle<Object> CompareNilIC::CompareNil(Handle<Object> object) {


 RUNTIME_FUNCTION(CompareNilIC_Miss) {
-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_ic_miss);
+  TimerEventScope<TimerEventIcMiss> timer(isolate);
  HandleScope scope(isolate);
  Handle<Object> object = args.at<Object>(0);
  CompareNilIC ic(isolate);
@ -3073,8 +3057,7 @@ Handle<Object> ToBooleanIC::ToBoolean(Handle<Object> object) {


 RUNTIME_FUNCTION(ToBooleanIC_Miss) {
-  Logger::TimerEventScope timer(
-      isolate, Logger::TimerEventScope::v8_ic_miss);
+  TimerEventScope<TimerEventIcMiss> timer(isolate);
  ASSERT(args.length() == 1);
  HandleScope scope(isolate);
  Handle<Object> object = args.at<Object>(0);
--- a/src/isolate.cc
+++ b/src/isolate.cc
@ -1878,9 +1878,9 @@ bool Isolate::Init(Deserializer* des) {
  builtins_.SetUp(this, create_heap_objects);

  if (FLAG_log_internal_timer_events) {
-    set_event_logger(Logger::LogInternalEvents);
+    set_event_logger(Logger::DefaultTimerEventsLogger);
  } else {
-    set_event_logger(Logger::EmptyLogInternalEvents);
+    set_event_logger(Logger::EmptyTimerEventsLogger);
  }

  // Set default value if not yet set.
--- a/src/log.cc
+++ b/src/log.cc
@ -924,7 +924,7 @@ void Logger::CurrentTimeEvent() {
 }


-void Logger::TimerEvent(StartEnd se, const char* name) {
+void Logger::TimerEvent(Logger::StartEnd se, const char* name) {
  if (!log_->IsEnabled()) return;
  ASSERT(FLAG_log_internal_timer_events);
  Log::MessageBuilder msg(log_);
@ -937,39 +937,40 @@ void Logger::TimerEvent(StartEnd se, const char* name) {


 void Logger::EnterExternal(Isolate* isolate) {
-  LOG(isolate, TimerEvent(START, TimerEventScope::v8_external));
+  LOG(isolate, TimerEvent(START, TimerEventExternal::name()));
  ASSERT(isolate->current_vm_state() == JS);
  isolate->set_current_vm_state(EXTERNAL);
 }


 void Logger::LeaveExternal(Isolate* isolate) {
-  LOG(isolate, TimerEvent(END, TimerEventScope::v8_external));
+  LOG(isolate, TimerEvent(END, TimerEventExternal::name()));
  ASSERT(isolate->current_vm_state() == EXTERNAL);
  isolate->set_current_vm_state(JS);
 }


-void Logger::LogInternalEvents(const char* name, int se) {
+void Logger::DefaultTimerEventsLogger(const char* name, int se) {
  Isolate* isolate = Isolate::Current();
  LOG(isolate, TimerEvent(static_cast<StartEnd>(se), name));
 }


-void Logger::TimerEventScope::LogTimerEvent(StartEnd se) {
-  isolate_->event_logger()(name_, se);
+template <class TimerEvent>
+void TimerEventScope<TimerEvent>::LogTimerEvent(Logger::StartEnd se) {
+  if (TimerEvent::expose_to_api() ||
+      isolate_->event_logger() == Logger::DefaultTimerEventsLogger) {
+    isolate_->event_logger()(TimerEvent::name(), se);
+  }
 }


-const char* Logger::TimerEventScope::v8_recompile_synchronous =
-    "V8.RecompileSynchronous";
-const char* Logger::TimerEventScope::v8_recompile_concurrent =
-    "V8.RecompileConcurrent";
-const char* Logger::TimerEventScope::v8_compile_full_code =
-    "V8.CompileFullCode";
-const char* Logger::TimerEventScope::v8_execute = "V8.Execute";
-const char* Logger::TimerEventScope::v8_external = "V8.External";
-const char* Logger::TimerEventScope::v8_ic_miss = "V8.IcMiss";
+// Instantiate template methods.
+#define V(TimerName, expose)                                           \
+  template void TimerEventScope<TimerEvent##TimerName>::LogTimerEvent( \
+      Logger::StartEnd se);
+TIMER_EVENTS_LIST(V)
+#undef V


 void Logger::LogRegExpSource(Handle<JSRegExp> regexp) {
--- a/src/log.h
+++ b/src/log.h
@ -151,6 +151,8 @@ class Sampler;

 class Logger {
 public:
+  enum StartEnd { START = 0, END = 1 };
+
 #define DECLARE_ENUM(enum_item, ignore) enum_item,
  enum LogEventsAndTags {
    LOG_EVENTS_AND_TAGS_LIST(DECLARE_ENUM)
@ -290,9 +292,6 @@ class Logger {
                          uintptr_t start,
                          uintptr_t end);

-  // ==== Events logged by --log-timer-events. ====
-  enum StartEnd { START, END };
-
  void CodeDeoptEvent(Code* code);
  void CurrentTimeEvent();

@ -301,33 +300,8 @@ class Logger {
  static void EnterExternal(Isolate* isolate);
  static void LeaveExternal(Isolate* isolate);

-  static void EmptyLogInternalEvents(const char* name, int se) { }
-  static void LogInternalEvents(const char* name, int se);
-
-  class TimerEventScope {
-   public:
-    TimerEventScope(Isolate* isolate, const char* name)
-        : isolate_(isolate), name_(name) {
-      LogTimerEvent(START);
-    }
-
-    ~TimerEventScope() {
-      LogTimerEvent(END);
-    }
-
-    void LogTimerEvent(StartEnd se);
-
-    static const char* v8_recompile_synchronous;
-    static const char* v8_recompile_concurrent;
-    static const char* v8_compile_full_code;
-    static const char* v8_execute;
-    static const char* v8_external;
-    static const char* v8_ic_miss;
-
-   private:
-    Isolate* isolate_;
-    const char* name_;
-  };
+  static void EmptyTimerEventsLogger(const char* name, int se) {}
+  static void DefaultTimerEventsLogger(const char* name, int se);

  // ==== Events logged by --log-regexp ====
  // Regexp compilation and execution events.
@ -446,6 +420,40 @@ class Logger {
 };


+#define TIMER_EVENTS_LIST(V)    \
+  V(RecompileSynchronous, true) \
+  V(RecompileConcurrent, true)  \
+  V(CompileFullCode, true)      \
+  V(Execute, true)              \
+  V(External, true)             \
+  V(IcMiss, false)
+
+#define V(TimerName, expose)                                                  \
+  class TimerEvent##TimerName : public AllStatic {                            \
+   public:                                                                    \
+    static const char* name(void* unused = NULL) { return "V8." #TimerName; } \
+    static bool expose_to_api() { return expose; }                            \
+  };
+TIMER_EVENTS_LIST(V)
+#undef V
+
+
+template <class TimerEvent>
+class TimerEventScope {
+ public:
+  explicit TimerEventScope(Isolate* isolate) : isolate_(isolate) {
+    LogTimerEvent(Logger::START);
+  }
+
+  ~TimerEventScope() { LogTimerEvent(Logger::END); }
+
+  void LogTimerEvent(Logger::StartEnd se);
+
+ private:
+  Isolate* isolate_;
+};
+
+
 class CodeEventListener {
 public:
  virtual ~CodeEventListener() {}
--- a/src/optimizing-compiler-thread.cc
+++ b/src/optimizing-compiler-thread.cc
@ -45,8 +45,7 @@ void OptimizingCompilerThread::Run() {

  while (true) {
    input_queue_semaphore_.Wait();
-    Logger::TimerEventScope timer(
-        isolate_, Logger::TimerEventScope::v8_recompile_concurrent);
+    TimerEventScope<TimerEventRecompileConcurrent> timer(isolate_);

    if (FLAG_concurrent_recompilation_delay != 0) {
      base::OS::Sleep(FLAG_concurrent_recompilation_delay);
--- a/src/vm-state-inl.h
+++ b/src/vm-state-inl.h
@ -40,8 +40,7 @@ template <StateTag Tag>
 VMState<Tag>::VMState(Isolate* isolate)
    : isolate_(isolate), previous_tag_(isolate->current_vm_state()) {
  if (FLAG_log_timer_events && previous_tag_ != EXTERNAL && Tag == EXTERNAL) {
-    LOG(isolate_,
-        TimerEvent(Logger::START, Logger::TimerEventScope::v8_external));
+    LOG(isolate_, TimerEvent(Logger::START, TimerEventExternal::name()));
  }
  isolate_->set_current_vm_state(Tag);
 }
@ -50,8 +49,7 @@ VMState<Tag>::VMState(Isolate* isolate)
 template <StateTag Tag>
 VMState<Tag>::~VMState() {
  if (FLAG_log_timer_events && previous_tag_ != EXTERNAL && Tag == EXTERNAL) {
-    LOG(isolate_,
-        TimerEvent(Logger::END, Logger::TimerEventScope::v8_external));
+    LOG(isolate_, TimerEvent(Logger::END, TimerEventExternal::name()));
  }
  isolate_->set_current_vm_state(previous_tag_);
 }