[log][api] introduce public CodeEventListener API

Introduce a new public API called CodeEventListener to allow embedders
to better support external profilers and other diagnostic tools without
relying on unsupported methods like --perf-basic-prof.

Bug: v8:7694
Cq-Include-Trybots: luci.chromium.try:linux_chromium_rel_ng
Change-Id: I063cc965394d59401358757634c9ea84c11517e9
Co-authored-by: Daniel Beckert <daniel@sthima.com.br>
Reviewed-on: https://chromium-review.googlesource.com/1028770
Commit-Queue: Yang Guo <yangguo@chromium.org>
Reviewed-by: Hannes Payer <hpayer@chromium.org>
Reviewed-by: Yang Guo <yangguo@chromium.org>
Reviewed-by: Andreas Haas <ahaas@chromium.org>
Cr-Commit-Position: refs/heads/master@{#53382}

include/v8-profiler.h

@@ -1009,6 +1009,76 @@ struct HeapStatsUpdate {
   uint32_t size;  // New value of size field for the interval with this index.
 };
 
+#define CODE_EVENTS_LIST(V) \
+  V(Builtin)                \
+  V(Callback)               \
+  V(Eval)                   \
+  V(Function)               \
+  V(InterpretedFunction)    \
+  V(Handler)                \
+  V(BytecodeHandler)        \
+  V(LazyCompile)            \
+  V(RegExp)                 \
+  V(Script)                 \
+  V(Stub)
+
+/**
+ * Note that this enum may be extended in the future. Please include a default
+ * case if this enum is used in a switch statement.
+ */
+enum CodeEventType {
+  kUnknownType = 0
+#define V(Name) , k##Name##Type
+  CODE_EVENTS_LIST(V)
+#undef V
+};
+
+/**
+ * Representation of a code creation event
+ */
+class V8_EXPORT CodeEvent {
+ public:
+  uintptr_t GetCodeStartAddress();
+  size_t GetCodeSize();
+  Local<String> GetFunctionName();
+  Local<String> GetScriptName();
+  int GetScriptLine();
+  int GetScriptColumn();
+  /**
+   * NOTE (mmarchini): We can't allocate objects in the heap when we collect
+   * existing code, and both the code type and the comment are not stored in the
+   * heap, so we return those as const char*.
+   */
+  CodeEventType GetCodeType();
+  const char* GetComment();
+
+  static const char* GetCodeEventTypeName(CodeEventType code_event_type);
+};
+
+/**
+ * Interface to listen to code creation events.
+ */
+class V8_EXPORT CodeEventHandler {
+ public:
+  /**
+   * Creates a new listener for the |isolate|. The isolate must be initialized.
+   * The listener object must be disposed after use by calling |Dispose| method.
+   * Multiple listeners can be created for the same isolate.
+   */
+  explicit CodeEventHandler(Isolate* isolate);
+  virtual ~CodeEventHandler();
+
+  virtual void Handle(CodeEvent* code_event) = 0;
+
+  void Enable();
+  void Disable();
+
+ private:
+  CodeEventHandler();
+  CodeEventHandler(const CodeEventHandler&);
+  CodeEventHandler& operator=(const CodeEventHandler&);
+  void* internal_listener_;
+};
 
 }  // namespace v8
 

src/api.cc

@@ -10162,6 +10162,70 @@ void CpuProfiler::SetIdle(bool is_idle) {
   isolate->SetIdle(is_idle);
 }
 
+uintptr_t CodeEvent::GetCodeStartAddress() {
+  return reinterpret_cast<i::CodeEvent*>(this)->code_start_address;
+}
+
+size_t CodeEvent::GetCodeSize() {
+  return reinterpret_cast<i::CodeEvent*>(this)->code_size;
+}
+
+Local<String> CodeEvent::GetFunctionName() {
+  return ToApiHandle<String>(
+      reinterpret_cast<i::CodeEvent*>(this)->function_name);
+}
+
+Local<String> CodeEvent::GetScriptName() {
+  return ToApiHandle<String>(
+      reinterpret_cast<i::CodeEvent*>(this)->script_name);
+}
+
+int CodeEvent::GetScriptLine() {
+  return reinterpret_cast<i::CodeEvent*>(this)->script_line;
+}
+
+int CodeEvent::GetScriptColumn() {
+  return reinterpret_cast<i::CodeEvent*>(this)->script_column;
+}
+
+CodeEventType CodeEvent::GetCodeType() {
+  return reinterpret_cast<i::CodeEvent*>(this)->code_type;
+}
+
+const char* CodeEvent::GetComment() {
+  return reinterpret_cast<i::CodeEvent*>(this)->comment;
+}
+
+const char* CodeEvent::GetCodeEventTypeName(CodeEventType code_event_type) {
+  switch (code_event_type) {
+    case kUnknownType:
+      return "Unknown";
+#define V(Name)       \
+  case k##Name##Type: \
+    return #Name;
+      CODE_EVENTS_LIST(V)
+#undef V
+  }
+}
+
+CodeEventHandler::CodeEventHandler(Isolate* isolate) {
+  internal_listener_ =
+      new i::ExternalCodeEventListener(reinterpret_cast<i::Isolate*>(isolate));
+}
+
+CodeEventHandler::~CodeEventHandler() {
+  delete reinterpret_cast<i::ExternalCodeEventListener*>(internal_listener_);
+}
+
+void CodeEventHandler::Enable() {
+  reinterpret_cast<i::ExternalCodeEventListener*>(internal_listener_)
+      ->StartListening(this);
+}
+
+void CodeEventHandler::Disable() {
+  reinterpret_cast<i::ExternalCodeEventListener*>(internal_listener_)
+      ->StopListening();
+}
 
 static i::HeapGraphEdge* ToInternal(const HeapGraphEdge* edge) {
   return const_cast<i::HeapGraphEdge*>(

src/code-events.h

@@ -24,32 +24,38 @@ class WasmCode;
 using WasmName = Vector<const char>;
 }  // namespace wasm
 
-#define LOG_EVENTS_AND_TAGS_LIST(V)                      \
-  V(CODE_CREATION_EVENT, "code-creation")                \
-  V(CODE_DISABLE_OPT_EVENT, "code-disable-optimization") \
-  V(CODE_MOVE_EVENT, "code-move")                        \
-  V(CODE_DELETE_EVENT, "code-delete")                    \
-  V(CODE_MOVING_GC, "code-moving-gc")                    \
-  V(SHARED_FUNC_MOVE_EVENT, "sfi-move")                  \
-  V(SNAPSHOT_CODE_NAME_EVENT, "snapshot-code-name")      \
-  V(TICK_EVENT, "tick")                                  \
-  V(BUILTIN_TAG, "Builtin")                              \
-  V(CALLBACK_TAG, "Callback")                            \
-  V(EVAL_TAG, "Eval")                                    \
-  V(FUNCTION_TAG, "Function")                            \
-  V(INTERPRETED_FUNCTION_TAG, "InterpretedFunction")     \
-  V(HANDLER_TAG, "Handler")                              \
-  V(BYTECODE_HANDLER_TAG, "BytecodeHandler")             \
-  V(LAZY_COMPILE_TAG, "LazyCompile")                     \
-  V(REG_EXP_TAG, "RegExp")                               \
-  V(SCRIPT_TAG, "Script")                                \
-  V(STUB_TAG, "Stub")                                    \
-  V(NATIVE_FUNCTION_TAG, "Function")                     \
-  V(NATIVE_LAZY_COMPILE_TAG, "LazyCompile")              \
-  V(NATIVE_SCRIPT_TAG, "Script")
+#define LOG_EVENTS_LIST(V)                             \
+  V(CODE_CREATION_EVENT, code-creation)                \
+  V(CODE_DISABLE_OPT_EVENT, code-disable-optimization) \
+  V(CODE_MOVE_EVENT, code-move)                        \
+  V(CODE_DELETE_EVENT, code-delete)                    \
+  V(CODE_MOVING_GC, code-moving-gc)                    \
+  V(SHARED_FUNC_MOVE_EVENT, sfi-move)                  \
+  V(SNAPSHOT_CODE_NAME_EVENT, snapshot-code-name)      \
+  V(TICK_EVENT, tick)
+
+#define TAGS_LIST(V)                               \
+  V(BUILTIN_TAG, Builtin)                          \
+  V(CALLBACK_TAG, Callback)                        \
+  V(EVAL_TAG, Eval)                                \
+  V(FUNCTION_TAG, Function)                        \
+  V(INTERPRETED_FUNCTION_TAG, InterpretedFunction) \
+  V(HANDLER_TAG, Handler)                          \
+  V(BYTECODE_HANDLER_TAG, BytecodeHandler)         \
+  V(LAZY_COMPILE_TAG, LazyCompile)                 \
+  V(REG_EXP_TAG, RegExp)                           \
+  V(SCRIPT_TAG, Script)                            \
+  V(STUB_TAG, Stub)                                \
+  V(NATIVE_FUNCTION_TAG, Function)                 \
+  V(NATIVE_LAZY_COMPILE_TAG, LazyCompile)          \
+  V(NATIVE_SCRIPT_TAG, Script)
 // Note that 'NATIVE_' cases for functions and scripts are mapped onto
 // original tags when writing to the log.
 
+#define LOG_EVENTS_AND_TAGS_LIST(V) \
+  LOG_EVENTS_LIST(V)                \
+  TAGS_LIST(V)
+
 #define PROFILE(the_isolate, Call) (the_isolate)->code_event_dispatcher()->Call;
 
 class CodeEventListener {
@@ -85,6 +91,8 @@ class CodeEventListener {
   enum DeoptKind { kSoft, kLazy, kEager };
   virtual void CodeDeoptEvent(Code* code, DeoptKind kind, Address pc,
                               int fp_to_sp_delta) = 0;
+
+  virtual bool is_listening_to_code_events() { return false; }
 };
 
 class CodeEventDispatcher {
@@ -101,6 +109,14 @@ class CodeEventDispatcher {
     base::LockGuard<base::Mutex> guard(&mutex_);
     listeners_.erase(listener);
   }
+  bool IsListeningToCodeEvents() {
+    for (auto it : listeners_) {
+      if (it->is_listening_to_code_events()) {
+        return true;
+      }
+    }
+    return false;
+  }
 
 #define CODE_EVENT_DISPATCH(code)              \
   base::LockGuard<base::Mutex> guard(&mutex_); \

src/compiler.cc

@@ -84,8 +84,9 @@ void LogFunctionCompilation(CodeEventListener::LogEventsAndTags tag,
   // Log the code generation. If source information is available include
   // script name and line number. Check explicitly whether logging is
   // enabled as finding the line number is not free.
-  if (!isolate->logger()->is_logging_code_events() &&
-      !isolate->is_profiling() && !FLAG_log_function_events) {
+  if (!isolate->logger()->is_listening_to_code_events() &&
+      !isolate->is_profiling() && !FLAG_log_function_events &&
+      !isolate->code_event_dispatcher()->IsListeningToCodeEvents()) {
     return;
   }
 

src/compiler/wasm-compiler.cc

@@ -3948,7 +3948,8 @@ Node* WasmGraphBuilder::AtomicOp(wasm::WasmOpcode opcode, Node* const* inputs,
 
 namespace {
 bool must_record_function_compilation(Isolate* isolate) {
-  return isolate->logger()->is_logging_code_events() || isolate->is_profiling();
+  return isolate->logger()->is_listening_to_code_events() ||
+         isolate->is_profiling();
 }
 
 PRINTF_FORMAT(4, 5)

src/heap/mark-compact.cc

@@ -2414,7 +2414,7 @@ void MarkCompactCollectorBase::CreateAndExecuteEvacuationTasks(
 
   const bool profiling =
       heap()->isolate()->is_profiling() ||
-      heap()->isolate()->logger()->is_logging_code_events() ||
+      heap()->isolate()->logger()->is_listening_to_code_events() ||
       heap()->isolate()->heap_profiler()->is_tracking_object_moves() ||
       heap()->has_heap_object_allocation_tracker();
   ProfilingMigrationObserver profiling_observer(heap());

src/isolate.cc

@@ -2893,7 +2893,7 @@ void CreateOffHeapTrampolines(Isolate* isolate) {
     // thus collected by the GC.
     builtins->set_builtin(i, *trampoline);
 
-    if (isolate->logger()->is_logging_code_events() ||
+    if (isolate->logger()->is_listening_to_code_events() ||
         isolate->is_profiling()) {
       isolate->logger()->LogCodeObject(*trampoline);
     }

src/isolate.h

@@ -57,6 +57,7 @@ class BuiltinsConstantsTableBuilder;
 class CallInterfaceDescriptorData;
 class CancelableTaskManager;
 class CodeEventDispatcher;
+class ExternalCodeEventListener;
 class CodeGenerator;
 class CodeRange;
 class CodeStubDescriptor;

src/log.h

@@ -8,6 +8,7 @@
 #include <set>
 #include <string>
 
+#include "include/v8-profiler.h"
 #include "src/allocation.h"
 #include "src/base/compiler-specific.h"
 #include "src/base/platform/elapsed-timer.h"
@@ -91,12 +92,33 @@ class WasmCode;
     if (logger->is_logging()) logger->Call;             \
   } while (false)
 
-#define LOG_CODE_EVENT(isolate, Call)                   \
-  do {                                                  \
-    v8::internal::Logger* logger = (isolate)->logger(); \
-    if (logger->is_logging_code_events()) logger->Call; \
+#define LOG_CODE_EVENT(isolate, Call)                        \
+  do {                                                       \
+    v8::internal::Logger* logger = (isolate)->logger();      \
+    if (logger->is_listening_to_code_events()) logger->Call; \
   } while (false)
 
+class ExistingCodeLogger {
+ public:
+  explicit ExistingCodeLogger(Isolate* isolate,
+                              CodeEventListener* listener = nullptr)
+      : isolate_(isolate), listener_(listener) {}
+
+  void LogCodeObjects();
+  void LogBytecodeHandlers();
+
+  void LogCompiledFunctions();
+  void LogExistingFunction(Handle<SharedFunctionInfo> shared,
+                           Handle<AbstractCode> code);
+  void LogCodeObject(Object* object);
+  void LogBytecodeHandler(interpreter::Bytecode bytecode,
+                          interpreter::OperandScale operand_scale, Code* code);
+
+ private:
+  Isolate* isolate_;
+  CodeEventListener* listener_;
+};
+
 class Logger : public CodeEventListener {
  public:
   enum StartEnd { START = 0, END = 1, STAMP = 2 };
@@ -229,7 +251,7 @@ class Logger : public CodeEventListener {
     return is_logging_;
   }
 
-  bool is_logging_code_events() {
+  bool is_listening_to_code_events() {
     return is_logging() || jit_logger_ != nullptr;
   }
 
@@ -327,6 +349,8 @@ class Logger : public CodeEventListener {
   // 'true' between SetUp() and TearDown().
   bool is_initialized_;
 
+  ExistingCodeLogger existing_code_logger_;
+
   base::ElapsedTimer timer_;
 
   friend class CpuProfiler;
@@ -407,6 +431,58 @@ class CodeEventLogger : public CodeEventListener {
   NameBuffer* name_buffer_;
 };
 
+struct CodeEvent {
+  uintptr_t code_start_address;
+  size_t code_size;
+  Handle<String> function_name;
+  Handle<String> script_name;
+  int script_line;
+  int script_column;
+  CodeEventType code_type;
+  const char* comment;
+};
+
+class ExternalCodeEventListener : public CodeEventListener {
+ public:
+  explicit ExternalCodeEventListener(Isolate* isolate);
+  ~ExternalCodeEventListener() override;
+
+  void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
+                       const char* comment) override;
+  void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
+                       Name* name) override;
+  void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
+                       SharedFunctionInfo* shared, Name* name) override;
+  void CodeCreateEvent(LogEventsAndTags tag, AbstractCode* code,
+                       SharedFunctionInfo* shared, Name* source, int line,
+                       int column) override;
+  void CodeCreateEvent(LogEventsAndTags tag, const wasm::WasmCode* code,
+                       wasm::WasmName name) override;
+
+  void RegExpCodeCreateEvent(AbstractCode* code, String* source) override;
+  void CallbackEvent(Name* name, Address entry_point) override {}
+  void GetterCallbackEvent(Name* name, Address entry_point) override {}
+  void SetterCallbackEvent(Name* name, Address entry_point) override {}
+  void SharedFunctionInfoMoveEvent(Address from, Address to) override {}
+  void CodeMoveEvent(AbstractCode* from, Address to) override {}
+  void CodeDisableOptEvent(AbstractCode* code,
+                           SharedFunctionInfo* shared) override {}
+  void CodeMovingGCEvent() override {}
+  void CodeDeoptEvent(Code* code, DeoptKind kind, Address pc,
+                      int fp_to_sp_delta) override {}
+
+  void StartListening(CodeEventHandler* code_event_handler);
+  void StopListening();
+
+  bool is_listening_to_code_events() override { return true; }
+
+ private:
+  void LogExistingCode();
+
+  bool is_listening_;
+  Isolate* isolate_;
+  v8::CodeEventHandler* code_event_handler_;
+};
 
 }  // namespace internal
 }  // namespace v8

src/runtime/runtime-function.cc

@@ -147,7 +147,8 @@ RUNTIME_FUNCTION(Runtime_SetCode) {
   // the target_shared optimized code map.
   JSFunction::EnsureFeedbackVector(target);
 
-  if (isolate->logger()->is_logging_code_events() || isolate->is_profiling()) {
+  if (isolate->logger()->is_listening_to_code_events() ||
+      isolate->is_profiling()) {
     isolate->logger()->LogExistingFunction(
         source_shared, Handle<AbstractCode>(source_shared->abstract_code()));
   }

src/snapshot/code-serializer.cc

@@ -287,7 +287,8 @@ MaybeHandle<SharedFunctionInfo> CodeSerializer::Deserialize(
     PrintF("[Deserializing from %d bytes took %0.3f ms]\n", length, ms);
   }
 
-  if (isolate->logger()->is_logging_code_events() || isolate->is_profiling()) {
+  if (isolate->logger()->is_listening_to_code_events() ||
+      isolate->is_profiling()) {
     String* name = isolate->heap()->empty_string();
     if (result->script()->IsScript()) {
       Script* script = Script::cast(result->script());

src/snapshot/snapshot-common.cc

@@ -115,7 +115,8 @@ Code* Snapshot::DeserializeBuiltin(Isolate* isolate, int builtin_id) {
            Builtins::name(builtin_id), bytes, ms);
   }
 
-  if (isolate->logger()->is_logging_code_events() || isolate->is_profiling()) {
+  if (isolate->logger()->is_listening_to_code_events() ||
+      isolate->is_profiling()) {
     isolate->logger()->LogCodeObject(code);
   }
 
@@ -196,7 +197,8 @@ Code* Snapshot::DeserializeHandler(Isolate* isolate,
            bytes, ms);
   }
 
-  if (isolate->logger()->is_logging_code_events() || isolate->is_profiling()) {
+  if (isolate->logger()->is_listening_to_code_events() ||
+      isolate->is_profiling()) {
     isolate->logger()->LogBytecodeHandler(bytecode, operand_scale, code);
   }
 

src/wasm/wasm-code-manager.cc

@@ -217,7 +217,7 @@ bool WasmCode::HasTrapHandlerIndex() const { return trap_handler_index_ >= 0; }
 void WasmCode::ResetTrapHandlerIndex() { trap_handler_index_ = -1; }
 
 bool WasmCode::ShouldBeLogged(Isolate* isolate) {
-  return isolate->logger()->is_logging_code_events() ||
+  return isolate->logger()->is_listening_to_code_events() ||
          isolate->is_profiling() || FLAG_print_wasm_code || FLAG_print_code;
 }
 

test/cctest/test-log.cc

@@ -35,6 +35,7 @@
 #endif  // __linux__
 
 #include <unordered_set>
+#include <vector>
 #include "src/api.h"
 #include "src/log-utils.h"
 #include "src/log.h"
@@ -251,6 +252,38 @@ class ScopedLoggerInitializer {
   DISALLOW_COPY_AND_ASSIGN(ScopedLoggerInitializer);
 };
 
+class TestCodeEventHandler : public v8::CodeEventHandler {
+ public:
+  explicit TestCodeEventHandler(v8::Isolate* isolate)
+      : v8::CodeEventHandler(isolate) {}
+
+  const char* FindLine(const char* prefix, const char* suffix = nullptr,
+                       const char* start = nullptr) {
+    if (!log_.length()) return NULL;
+    const char* c_log = log_.c_str();
+    if (start == nullptr) start = c_log;
+    const char* end = c_log + log_.length();
+    return FindLogLine(start, end, prefix, suffix);
+  }
+
+  void Handle(v8::CodeEvent* code_event) override {
+    const char* code_type =
+        v8::CodeEvent::GetCodeEventTypeName(code_event->GetCodeType());
+    char function_name[1000];
+    strncpy(function_name, code_type, 1000);
+    function_name[strlen(code_type)] = ' ';
+    code_event->GetFunctionName()->WriteUtf8(
+        function_name + strlen(code_type) + 1, 1000);
+    function_name[strlen(function_name) + 1] = '\0';
+    function_name[strlen(function_name)] = '\n';
+
+    log_ += std::string(function_name);
+  }
+
+ private:
+  std::string log_;
+};
+
 }  // namespace
 
 TEST(FindLogLine) {
@@ -800,6 +833,48 @@ TEST(LogInterpretedFramesNativeStack) {
   isolate->Dispose();
 }
 
+TEST(ExternalCodeEventListener) {
+  i::FLAG_log = false;
+  i::FLAG_prof = false;
+
+  v8::Isolate::CreateParams create_params;
+  create_params.array_buffer_allocator = CcTest::array_buffer_allocator();
+  v8::Isolate* isolate = v8::Isolate::New(create_params);
+
+  {
+    v8::HandleScope scope(isolate);
+    v8::Isolate::Scope isolate_scope(isolate);
+    v8::Local<v8::Context> context = v8::Context::New(isolate);
+    context->Enter();
+
+    TestCodeEventHandler code_event_handler(isolate);
+
+    const char* source_text_before_start =
+        "function testCodeEventListenerBeforeStart(a,b) { return a + b };"
+        "testCodeEventListenerBeforeStart('1', 1);";
+    CompileRun(source_text_before_start);
+
+    CHECK_NULL(code_event_handler.FindLine("LazyCompile",
+                                           "testCodeEventListenerBeforeStart"));
+
+    code_event_handler.Enable();
+
+    CHECK_NOT_NULL(code_event_handler.FindLine(
+        "LazyCompile", "testCodeEventListenerBeforeStart"));
+
+    const char* source_text_after_start =
+        "function testCodeEventListenerAfterStart(a,b) { return a + b };"
+        "testCodeEventListenerAfterStart('1', 1);";
+    CompileRun(source_text_after_start);
+
+    CHECK_NOT_NULL(code_event_handler.FindLine(
+        "LazyCompile", "testCodeEventListenerAfterStart"));
+
+    context->Exit();
+  }
+  isolate->Dispose();
+}
+
 TEST(TraceMaps) {
   SETUP_FLAGS();
   i::FLAG_trace_maps = true;