[TurboFan] Print more information in logs related to dependency change

When marking the function for a deopt due a dependency change, we
only print the information about the code object. This isn't very
useful when looking at the output of --trace-deopt. This cl also adds
SharedFunctionInfo which makes it easier to see which function got
deoptimized. Also adds these events to the log file so they can be used
in profview to print more accurate deoptimization information.

Change-Id: I1b7a88b5cc2a1ad1ebb0863cf8a4f7d2e151b76a
Reviewed-on: https://chromium-review.googlesource.com/c/v8/v8/+/2281001
Commit-Queue: Mythri Alle <mythria@chromium.org>
Reviewed-by: Peter Marshall <petermarshall@chromium.org>
Reviewed-by: Georg Neis <neis@chromium.org>
Reviewed-by: Ross McIlroy <rmcilroy@chromium.org>
Cr-Commit-Position: refs/heads/master@{#68705}

src/logging/code-events.h

@@ -100,6 +100,11 @@ class CodeEventListener {
                                    Handle<SharedFunctionInfo> shared) = 0;
   virtual void CodeDeoptEvent(Handle<Code> code, DeoptimizeKind kind,
                               Address pc, int fp_to_sp_delta) = 0;
+  // These events can happen when 1. an assumption made by optimized code fails
+  // or 2. a weakly embedded object dies.
+  virtual void CodeDependencyChangeEvent(Handle<Code> code,
+                                         Handle<SharedFunctionInfo> shared,
+                                         const char* reason) = 0;
 
   virtual bool is_listening_to_code_events() { return false; }
 };
@@ -220,6 +225,13 @@ class CodeEventDispatcher : public CodeEventListener {
       listener->CodeDeoptEvent(code, kind, pc, fp_to_sp_delta);
     });
   }
+  void CodeDependencyChangeEvent(Handle<Code> code,
+                                 Handle<SharedFunctionInfo> sfi,
+                                 const char* reason) override {
+    DispatchEventToListeners([=](CodeEventListener* listener) {
+      listener->CodeDependencyChangeEvent(code, sfi, reason);
+    });
+  }
 
  private:
   std::unordered_set<CodeEventListener*> listeners_;

src/logging/log.cc

@@ -1377,33 +1377,45 @@ void Logger::CodeDisableOptEvent(Handle<AbstractCode> code,
   msg.WriteToLogFile();
 }
 
-void Logger::CodeDeoptEvent(Handle<Code> code, DeoptimizeKind kind, Address pc,
-                            int fp_to_sp_delta) {
-  if (!log_->IsEnabled()) return;
-  Deoptimizer::DeoptInfo info = Deoptimizer::GetDeoptInfo(*code, pc);
+void Logger::ProcessDeoptEvent(Handle<Code> code, SourcePosition position,
+                               const char* kind, const char* reason) {
   Log::MessageBuilder msg(log_.get());
   msg << "code-deopt" << kNext << timer_.Elapsed().InMicroseconds() << kNext
       << code->CodeSize() << kNext
       << reinterpret_cast<void*>(code->InstructionStart());
 
-  // Deoptimization position.
   std::ostringstream deopt_location;
   int inlining_id = -1;
   int script_offset = -1;
-  if (info.position.IsKnown()) {
-    info.position.Print(deopt_location, *code);
-    inlining_id = info.position.InliningId();
-    script_offset = info.position.ScriptOffset();
+  if (position.IsKnown()) {
+    position.Print(deopt_location, *code);
+    inlining_id = position.InliningId();
+    script_offset = position.ScriptOffset();
   } else {
     deopt_location << "<unknown>";
   }
   msg << kNext << inlining_id << kNext << script_offset << kNext;
-  msg << Deoptimizer::MessageFor(kind) << kNext;
-  msg << deopt_location.str().c_str() << kNext
-      << DeoptimizeReasonToString(info.deopt_reason);
+  msg << kind << kNext;
+  msg << deopt_location.str().c_str() << kNext << reason;
   msg.WriteToLogFile();
 }
 
+void Logger::CodeDeoptEvent(Handle<Code> code, DeoptimizeKind kind, Address pc,
+                            int fp_to_sp_delta) {
+  if (!log_->IsEnabled()) return;
+  Deoptimizer::DeoptInfo info = Deoptimizer::GetDeoptInfo(*code, pc);
+  ProcessDeoptEvent(code, info.position, Deoptimizer::MessageFor(kind),
+                    DeoptimizeReasonToString(info.deopt_reason));
+}
+
+void Logger::CodeDependencyChangeEvent(Handle<Code> code,
+                                       Handle<SharedFunctionInfo> sfi,
+                                       const char* reason) {
+  if (!log_->IsEnabled()) return;
+  SourcePosition position(sfi->StartPosition(), -1);
+  ProcessDeoptEvent(code, position, "dependency-change", reason);
+}
+
 namespace {
 
 void CodeLinePosEvent(

src/logging/log.h

@@ -67,6 +67,7 @@ class LowLevelLogger;
 class PerfBasicLogger;
 class PerfJitLogger;
 class Profiler;
+class SourcePosition;
 class Ticker;
 
 #undef LOG
@@ -213,6 +214,12 @@ class Logger : public CodeEventListener {
                            Handle<SharedFunctionInfo> shared) override;
   void CodeDeoptEvent(Handle<Code> code, DeoptimizeKind kind, Address pc,
                       int fp_to_sp_delta) override;
+  void CodeDependencyChangeEvent(Handle<Code> code,
+                                 Handle<SharedFunctionInfo> sfi,
+                                 const char* reason) override;
+
+  void ProcessDeoptEvent(Handle<Code> code, SourcePosition position,
+                         const char* kind, const char* reason);
 
   // Emits a code line info record event.
   void CodeLinePosInfoRecordEvent(Address code_start,
@@ -398,6 +405,9 @@ class V8_EXPORT_PRIVATE CodeEventLogger : public CodeEventListener {
   void CodeMovingGCEvent() override {}
   void CodeDeoptEvent(Handle<Code> code, DeoptimizeKind kind, Address pc,
                       int fp_to_sp_delta) override {}
+  void CodeDependencyChangeEvent(Handle<Code> code,
+                                 Handle<SharedFunctionInfo> sfi,
+                                 const char* reason) override {}
 
  protected:
   Isolate* isolate_;
@@ -458,6 +468,9 @@ class ExternalCodeEventListener : public CodeEventListener {
   void CodeMovingGCEvent() override {}
   void CodeDeoptEvent(Handle<Code> code, DeoptimizeKind kind, Address pc,
                       int fp_to_sp_delta) override {}
+  void CodeDependencyChangeEvent(Handle<Code> code,
+                                 Handle<SharedFunctionInfo> sfi,
+                                 const char* reason) override {}
 
   void StartListening(v8::CodeEventHandler* code_event_handler);
   void StopListening();

src/objects/code.cc

@@ -1011,11 +1011,22 @@ void Code::SetMarkedForDeoptimization(const char* reason) {
       (deoptimization_data() != GetReadOnlyRoots().empty_fixed_array())) {
     DeoptimizationData deopt_data =
         DeoptimizationData::cast(deoptimization_data());
-    CodeTracer::Scope scope(GetIsolate()->GetCodeTracer());
-    PrintF(scope.file(),
-           "[marking dependent code " V8PRIxPTR_FMT
-           " (opt #%d) for deoptimization, reason: %s]\n",
-           ptr(), deopt_data.OptimizationId().value(), reason);
+    auto isolate = GetIsolate();
+    CodeTracer::Scope scope(isolate->GetCodeTracer());
+    PrintF(scope.file(), "[marking dependent code " V8PRIxPTR_FMT " ", ptr());
+    deopt_data.SharedFunctionInfo().ShortPrint(scope.file());
+    PrintF(" (opt #%d) for deoptimization, reason: %s]\n",
+           deopt_data.OptimizationId().value(), reason);
+    {
+      HandleScope scope(isolate);
+      PROFILE(
+          isolate,
+          CodeDependencyChangeEvent(
+              handle(*this, isolate),
+              handle(SharedFunctionInfo::cast(deopt_data.SharedFunctionInfo()),
+                     isolate),
+              reason));
+    }
   }
 }
 

src/profiler/profiler-listener.h

@@ -56,6 +56,9 @@ class V8_EXPORT_PRIVATE ProfilerListener : public CodeEventListener {
                            Handle<SharedFunctionInfo> shared) override;
   void CodeDeoptEvent(Handle<Code> code, DeoptimizeKind kind, Address pc,
                       int fp_to_sp_delta) override;
+  void CodeDependencyChangeEvent(Handle<Code> code,
+                                 Handle<SharedFunctionInfo> sfi,
+                                 const char* reason) override {}
 
   const char* GetName(Name name) {
     return function_and_resource_names_.GetName(name);

src/runtime/runtime-test.cc

@@ -1588,6 +1588,9 @@ RUNTIME_FUNCTION(Runtime_EnableCodeLoggingForTesting) {
                              Handle<SharedFunctionInfo> shared) final {}
     void CodeDeoptEvent(Handle<Code> code, DeoptimizeKind kind, Address pc,
                         int fp_to_sp_delta) final {}
+    void CodeDependencyChangeEvent(Handle<Code> code,
+                                   Handle<SharedFunctionInfo> shared,
+                                   const char* reason) final {}
 
     bool is_listening_to_code_events() final { return true; }
   };