Include stack traces in console messages (#44150)

Summary:
Pull Request resolved: https://github.com/facebook/react-native/pull/44150

Changelog: [Internal]

* Adds the `RuntimeTargetDelegate::captureStackTrace` method for capturing stack traces during JS execution. The returned stack traces are opaque to RN, but may be passed back into the `RuntimeTargetDelegate`, particularly through the `addConsoleMessage` method.
* Implements `captureStackTrace` for Hermes (based on D55757947).
* Integrates `captureStackTrace` into the `console` handler (`RuntimeTargetConsole`)

Reviewed By: hoxyq

Differential Revision: D55474512

fbshipit-source-id: 3547d756844fa24c24cd9bcdc507b33c6ab673a9

packages/react-native/ReactCommon/hermes/inspector-modern/chrome/HermesRuntimeTargetDelegate.cpp

@@ -29,6 +29,25 @@ namespace facebook::react::jsinspector_modern {
 
 #ifdef HERMES_ENABLE_DEBUGGER
 class HermesRuntimeTargetDelegate::Impl final : public RuntimeTargetDelegate {
+  using HermesStackTrace = debugger::StackTrace;
+
+  class HermesStackTraceWrapper : public StackTrace {
+   public:
+    explicit HermesStackTraceWrapper(HermesStackTrace&& hermesStackTrace)
+        : hermesStackTrace_{std::move(hermesStackTrace)} {}
+
+    HermesStackTrace& operator*() {
+      return hermesStackTrace_;
+    }
+
+    HermesStackTrace* operator->() {
+      return &hermesStackTrace_;
+    }
+
+   private:
+    HermesStackTrace hermesStackTrace_;
+  };
+
  public:
   explicit Impl(
       HermesRuntimeTargetDelegate& delegate,
@@ -118,14 +137,36 @@ class HermesRuntimeTargetDelegate::Impl final : public RuntimeTargetDelegate {
       default:
         throw std::logic_error{"Unknown console message type"};
     }
-    cdpDebugAPI_->addConsoleMessage(
-        HermesConsoleMessage{message.timestamp, type, std::move(message.args)});
+    HermesStackTrace hermesStackTrace{};
+    if (auto hermesStackTraceWrapper =
+            dynamic_cast<HermesStackTraceWrapper*>(message.stackTrace.get())) {
+      hermesStackTrace = std::move(**hermesStackTraceWrapper);
+    }
+    HermesConsoleMessage hermesConsoleMessage{
+        message.timestamp, type, std::move(message.args)};
+    // NOTE: HermesConsoleMessage should really have a constructor that takes a
+    // stack trace.
+    hermesConsoleMessage.stackTrace = std::move(hermesStackTrace);
+    cdpDebugAPI_->addConsoleMessage(std::move(hermesConsoleMessage));
   }
 
   bool supportsConsole() const override {
     return true;
   }
 
+  std::unique_ptr<StackTrace> captureStackTrace(
+      jsi::Runtime& /* runtime */,
+      size_t /* framesToSkip */) override {
+    // TODO(moti): Pass framesToSkip to Hermes. Ignoring framesToSkip happens
+    // to work for our current use case, because the HostFunction frame we want
+    // to skip is stripped by CDPDebugAPI::addConsoleMessage before being sent
+    // to the client. This is still conceptually wrong and could block us from
+    // properly representing the stack trace in other use cases, where native
+    // frames aren't stripped on serialisation.
+    return std::make_unique<HermesStackTraceWrapper>(
+        runtime_->getDebugger().captureStackTrace());
+  }
+
  private:
   HermesRuntimeTargetDelegate& delegate_;
   std::shared_ptr<HermesRuntime> runtime_;
@@ -181,6 +222,12 @@ bool HermesRuntimeTargetDelegate::supportsConsole() const {
   return impl_->supportsConsole();
 }
 
+std::unique_ptr<StackTrace> HermesRuntimeTargetDelegate::captureStackTrace(
+    jsi::Runtime& runtime,
+    size_t framesToSkip) {
+  return impl_->captureStackTrace(runtime, framesToSkip);
+}
+
 #ifdef HERMES_ENABLE_DEBUGGER
 CDPDebugAPI& HermesRuntimeTargetDelegate::getCDPDebugAPI() {
   return impl_->getCDPDebugAPI();

packages/react-native/ReactCommon/hermes/inspector-modern/chrome/HermesRuntimeTargetDelegate.h

@@ -50,6 +50,10 @@ class HermesRuntimeTargetDelegate : public RuntimeTargetDelegate {
 
   bool supportsConsole() const override;
 
+  std::unique_ptr<StackTrace> captureStackTrace(
+      jsi::Runtime& runtime,
+      size_t framesToSkip) override;
+
  private:
   // We use the private implementation idiom to ensure this class has the same
   // layout regardless of whether HERMES_ENABLE_DEBUGGER is defined. The net

packages/react-native/ReactCommon/jsinspector-modern/ConsoleMessage.h

@@ -7,6 +7,8 @@
 
 #pragma once
 
+#include "StackTrace.h"
+
 #include <vector>
 
 #include <jsi/jsi.h>
@@ -57,18 +59,23 @@ struct SimpleConsoleMessage {
 };
 
 /**
- * A console message made of JSI values.
+ * A console message made of JSI values and a captured stack trace.
  */
 struct ConsoleMessage {
   double timestamp;
   ConsoleAPIType type;
   std::vector<jsi::Value> args;
+  std::unique_ptr<StackTrace> stackTrace;
 
   ConsoleMessage(
       double timestamp,
       ConsoleAPIType type,
-      std::vector<jsi::Value> args)
-      : timestamp(timestamp), type(type), args(std::move(args)) {}
+      std::vector<jsi::Value> args,
+      std::unique_ptr<StackTrace> stackTrace = StackTrace::empty())
+      : timestamp(timestamp),
+        type(type),
+        args(std::move(args)),
+        stackTrace(std::move(stackTrace)) {}
 
   ConsoleMessage(jsi::Runtime& runtime, SimpleConsoleMessage message);
 

packages/react-native/ReactCommon/jsinspector-modern/FallbackRuntimeTargetDelegate.cpp

@@ -36,4 +36,12 @@ bool FallbackRuntimeTargetDelegate::supportsConsole() const {
   return false;
 }
 
+std::unique_ptr<StackTrace> FallbackRuntimeTargetDelegate::captureStackTrace(
+    jsi::Runtime& /*runtime*/,
+    size_t /*framesToSkip*/
+) {
+  // TODO: Parse a JS `Error().stack` as a fallback
+  return std::make_unique<StackTrace>();
+}
+
 } // namespace facebook::react::jsinspector_modern

packages/react-native/ReactCommon/jsinspector-modern/FallbackRuntimeTargetDelegate.h

@@ -36,6 +36,10 @@ class FallbackRuntimeTargetDelegate : public RuntimeTargetDelegate {
 
   bool supportsConsole() const override;
 
+  std::unique_ptr<StackTrace> captureStackTrace(
+      jsi::Runtime& runtime,
+      size_t framesToSkip) override;
+
  private:
   std::string engineDescription_;
 };

packages/react-native/ReactCommon/jsinspector-modern/RuntimeTarget.h

@@ -14,6 +14,7 @@
 #include "InspectorInterfaces.h"
 #include "RuntimeAgent.h"
 #include "ScopedExecutor.h"
+#include "StackTrace.h"
 #include "WeakList.h"
 
 #include <memory>
@@ -73,6 +74,22 @@ class RuntimeTargetDelegate {
    * \c addConsoleMessage MAY be called even if this method returns false.
    */
   virtual bool supportsConsole() const = 0;
+
+  /**
+   * \returns an opaque representation of a stack trace. This may be passed back
+   * to the `RuntimeTargetDelegate` as part of `addConsoleMessage` or other APIs
+   * that report stack traces.
+   * \param framesToSkip The number of call frames to skip. The first call frame
+   * is the topmost (current) frame on the Runtime's call stack, which will
+   * typically be the (native) JSI HostFunction that called this method.
+   * \note The method is called on the JS thread, and receives a valid reference
+   * to the current \c jsi::Runtime. The callee MAY use its own intrinsic
+   * Runtime reference, if it has one, without checking it for equivalence with
+   * the one provided here.
+   */
+  virtual std::unique_ptr<StackTrace> captureStackTrace(
+      jsi::Runtime& runtime,
+      size_t framesToSkip = 0) = 0;
 };
 
 /**

packages/react-native/ReactCommon/jsinspector-modern/RuntimeTargetConsole.cpp

@@ -187,7 +187,8 @@ void RuntimeTarget::installConsoleHandler() {
                 size_t count,
                 RuntimeTargetDelegate& runtimeTargetDelegate,
                 ConsoleState& state,
-                double timestampMs)>&& body) {
+                double timestampMs,
+                std::unique_ptr<StackTrace> stackTrace)>&& body) {
           console.setProperty(
               runtime,
               methodName,
@@ -210,13 +211,17 @@ void RuntimeTarget::installConsoleHandler() {
                              body = std::move(body),
                              state,
                              timestampMs](auto& runtimeTargetDelegate) {
+                              auto stackTrace =
+                                  runtimeTargetDelegate.captureStackTrace(
+                                      runtime, /* framesToSkip */ 1);
                               body(
                                   runtime,
                                   args,
                                   count,
                                   runtimeTargetDelegate,
                                   *state,
-                                  timestampMs);
+                                  timestampMs,
+                                  std::move(stackTrace));
                             });
                         return jsi::Value::undefined();
                       })));
@@ -232,7 +237,8 @@ void RuntimeTarget::installConsoleHandler() {
            size_t count,
            RuntimeTargetDelegate& runtimeTargetDelegate,
            ConsoleState& state,
-           auto timestampMs) {
+           auto timestampMs,
+           std::unique_ptr<StackTrace> stackTrace) {
           std::string label = "default";
           if (count > 0 && !args[0].isUndefined()) {
             label = args[0].toString(runtime).utf8(runtime);
@@ -247,7 +253,11 @@ void RuntimeTarget::installConsoleHandler() {
           vec.emplace_back(jsi::String::createFromUtf8(
               runtime, label + ": "s + std::to_string(it->second)));
           runtimeTargetDelegate.addConsoleMessage(
-              runtime, {timestampMs, ConsoleAPIType::kCount, std::move(vec)});
+              runtime,
+              {timestampMs,
+               ConsoleAPIType::kCount,
+               std::move(vec),
+               std::move(stackTrace)});
         });
 
     /**
@@ -260,7 +270,8 @@ void RuntimeTarget::installConsoleHandler() {
            size_t count,
            RuntimeTargetDelegate& runtimeTargetDelegate,
            ConsoleState& state,
-           auto timestampMs) {
+           auto timestampMs,
+           std::unique_ptr<StackTrace> stackTrace) {
           std::string label = "default";
           if (count > 0 && !args[0].isUndefined()) {
             label = args[0].toString(runtime).utf8(runtime);
@@ -272,7 +283,10 @@ void RuntimeTarget::installConsoleHandler() {
                 runtime, "Count for '"s + label + "' does not exist"));
             runtimeTargetDelegate.addConsoleMessage(
                 runtime,
-                {timestampMs, ConsoleAPIType::kWarning, std::move(vec)});
+                {timestampMs,
+                 ConsoleAPIType::kWarning,
+                 std::move(vec),
+                 std::move(stackTrace)});
           } else {
             it->second = 0;
           }
@@ -288,7 +302,8 @@ void RuntimeTarget::installConsoleHandler() {
            size_t count,
            RuntimeTargetDelegate& runtimeTargetDelegate,
            ConsoleState& state,
-           auto timestampMs) {
+           auto timestampMs,
+           std::unique_ptr<StackTrace> stackTrace) {
           std::string label = "default";
           if (count > 0 && !args[0].isUndefined()) {
             label = args[0].toString(runtime).utf8(runtime);
@@ -302,7 +317,10 @@ void RuntimeTarget::installConsoleHandler() {
                 runtime, "Timer '"s + label + "' already exists"));
             runtimeTargetDelegate.addConsoleMessage(
                 runtime,
-                {timestampMs, ConsoleAPIType::kWarning, std::move(vec)});
+                {timestampMs,
+                 ConsoleAPIType::kWarning,
+                 std::move(vec),
+                 std::move(stackTrace)});
           }
         });
 
@@ -316,7 +334,8 @@ void RuntimeTarget::installConsoleHandler() {
            size_t count,
            RuntimeTargetDelegate& runtimeTargetDelegate,
            ConsoleState& state,
-           auto timestampMs) {
+           auto timestampMs,
+           std::unique_ptr<StackTrace> stackTrace) {
           std::string label = "default";
           if (count > 0 && !args[0].isUndefined()) {
             label = args[0].toString(runtime).utf8(runtime);
@@ -328,7 +347,10 @@ void RuntimeTarget::installConsoleHandler() {
                 runtime, "Timer '"s + label + "' does not exist"));
             runtimeTargetDelegate.addConsoleMessage(
                 runtime,
-                {timestampMs, ConsoleAPIType::kWarning, std::move(vec)});
+                {timestampMs,
+                 ConsoleAPIType::kWarning,
+                 std::move(vec),
+                 std::move(stackTrace)});
           } else {
             std::vector<jsi::Value> vec;
             vec.emplace_back(jsi::String::createFromUtf8(
@@ -338,7 +360,10 @@ void RuntimeTarget::installConsoleHandler() {
             state.timerTable.erase(it);
             runtimeTargetDelegate.addConsoleMessage(
                 runtime,
-                {timestampMs, ConsoleAPIType::kTimeEnd, std::move(vec)});
+                {timestampMs,
+                 ConsoleAPIType::kTimeEnd,
+                 std::move(vec),
+                 std::move(stackTrace)});
           }
         });
 
@@ -352,7 +377,8 @@ void RuntimeTarget::installConsoleHandler() {
            size_t count,
            RuntimeTargetDelegate& runtimeTargetDelegate,
            ConsoleState& state,
-           auto timestampMs) {
+           auto timestampMs,
+           std::unique_ptr<StackTrace> stackTrace) {
           std::string label = "default";
           if (count > 0 && !args[0].isUndefined()) {
             label = args[0].toString(runtime).utf8(runtime);
@@ -364,7 +390,10 @@ void RuntimeTarget::installConsoleHandler() {
                 runtime, "Timer '"s + label + "' does not exist"));
             runtimeTargetDelegate.addConsoleMessage(
                 runtime,
-                {timestampMs, ConsoleAPIType::kWarning, std::move(vec)});
+                {timestampMs,
+                 ConsoleAPIType::kWarning,
+                 std::move(vec),
+                 std::move(stackTrace)});
           } else {
             std::vector<jsi::Value> vec;
             vec.emplace_back(jsi::String::createFromUtf8(
@@ -377,7 +406,11 @@ void RuntimeTarget::installConsoleHandler() {
               }
             }
             runtimeTargetDelegate.addConsoleMessage(
-                runtime, {timestampMs, ConsoleAPIType::kLog, std::move(vec)});
+                runtime,
+                {timestampMs,
+                 ConsoleAPIType::kLog,
+                 std::move(vec),
+                 std::move(stackTrace)});
           }
         });
 
@@ -391,7 +424,8 @@ void RuntimeTarget::installConsoleHandler() {
            size_t count,
            RuntimeTargetDelegate& runtimeTargetDelegate,
            ConsoleState& /*state*/,
-           auto timestampMs) {
+           auto timestampMs,
+           std::unique_ptr<StackTrace> stackTrace) {
           if (count >= 1 && toBoolean(runtime, args[0])) {
             return;
           }
@@ -420,7 +454,8 @@ void RuntimeTarget::installConsoleHandler() {
                ConsoleAPIType::kAssert,
                std::vector<jsi::Value>(
                    make_move_iterator(data.begin()),
-                   make_move_iterator(data.end()))});
+                   make_move_iterator(data.end())),
+               std::move(stackTrace)});
         });
 
     for (auto& [name, type] : kForwardingConsoleMethods) {
@@ -432,13 +467,15 @@ void RuntimeTarget::installConsoleHandler() {
               size_t count,
               RuntimeTargetDelegate& runtimeTargetDelegate,
               ConsoleState& /*state*/,
-              auto timestampMs) {
+              auto timestampMs,
+              std::unique_ptr<StackTrace> stackTrace) {
             std::vector<jsi::Value> argsVec;
             for (size_t i = 0; i != count; ++i) {
               argsVec.emplace_back(runtime, args[i]);
             }
             runtimeTargetDelegate.addConsoleMessage(
-                runtime, {timestampMs, type, std::move(argsVec)});
+                runtime,
+                {timestampMs, type, std::move(argsVec), std::move(stackTrace)});
           });
     }
 

packages/react-native/ReactCommon/jsinspector-modern/StackTrace.h

@@ -0,0 +1,39 @@
+/*
+ * Copyright (c) Meta Platforms, Inc. and affiliates.
+ *
+ * This source code is licensed under the MIT license found in the
+ * LICENSE file in the root directory of this source tree.
+ */
+
+#pragma once
+
+#include <memory>
+
+namespace facebook::react::jsinspector_modern {
+
+/**
+ * An opaque representation of a stack trace.
+ */
+class StackTrace {
+ public:
+  /**
+   * Constructs an empty stack trace.
+   */
+  static inline std::unique_ptr<StackTrace> empty() {
+    return std::make_unique<StackTrace>();
+  }
+
+  /**
+   * Constructs an empty stack trace.
+   */
+  StackTrace() = default;
+
+  StackTrace(const StackTrace&) = delete;
+  StackTrace& operator=(const StackTrace&) = delete;
+  StackTrace(StackTrace&&) = delete;
+  StackTrace& operator=(StackTrace&&) = delete;
+
+  virtual ~StackTrace() = default;
+};
+
+} // namespace facebook::react::jsinspector_modern

packages/react-native/ReactCommon/jsinspector-modern/tests/ConsoleApiTest.cpp

@@ -51,6 +51,27 @@ class ConsoleApiTest
   void SetUp() override {
     JsiIntegrationPortableTest::SetUp();
     connect();
+    EXPECT_CALL(
+        fromPage(),
+        onMessage(
+            JsonParsed(AllOf(AtJsonPtr("/method", "Debugger.scriptParsed")))))
+        .Times(AnyNumber())
+        .WillRepeatedly(Invoke<>([this](std::string message) {
+          auto params = folly::parseJson(message);
+          // Store the script ID and URL for later use.
+          scriptUrlsById_.emplace(
+              params.at("params").at("scriptId").getString(),
+              params.at("params").at("url").getString());
+        }));
+    this->expectMessageFromPage(JsonEq(R"({
+                                            "id": 0,
+                                            "result": {}
+                                        })"));
+    this->toPage_->sendMessage(R"({
+                                    "id": 0,
+                                    "method": "Debugger.enable"
+                                })");
+
     if (GetParam().runtimeEnabledAtStart) {
       enableRuntimeDomain();
     }
@@ -79,7 +100,22 @@ class ConsoleApiTest
     expectedConsoleApiCalls_.clear();
   }
 
+  template <typename InnerMatcher>
+  Matcher<folly::dynamic> ScriptIdMapsTo(InnerMatcher urlMatcher) {
+    return ResultOf(
+        [this](const auto& id) { return getScriptUrlById(id.getString()); },
+        urlMatcher);
+  }
+
  private:
+  std::optional<std::string> getScriptUrlById(std::string scriptId) {
+    auto it = scriptUrlsById_.find(scriptId);
+    if (it == scriptUrlsById_.end()) {
+      return std::nullopt;
+    }
+    return it->second;
+  }
+
   void expectConsoleApiCallImpl(Matcher<folly::dynamic> paramsMatcher) {
     this->expectMessageFromPage(JsonParsed(AllOf(
         AtJsonPtr("/method", "Runtime.consoleAPICalled"),
@@ -137,6 +173,7 @@ class ConsoleApiTest
 
   std::vector<Matcher<folly::dynamic>> expectedConsoleApiCalls_;
   bool runtimeEnabled_{false};
+  std::unordered_map<std::string, std::string> scriptUrlsById_;
 };
 
 class ConsoleApiTestWithPreExistingConsole : public ConsoleApiTest {
@@ -679,6 +716,38 @@ TEST_P(ConsoleApiTestWithPreExistingConsole, testPreExistingConsoleObject) {
           }])"));
 }
 
+TEST_P(ConsoleApiTest, testConsoleLogStack) {
+  InSequence s;
+  expectConsoleApiCall(AllOf(
+      AtJsonPtr("/type", "log"),
+      AtJsonPtr(
+          "/args",
+          R"([{
+                "type": "string",
+                "value": "hello"
+              }])"_json),
+      AtJsonPtr(
+          "/stackTrace/callFrames",
+          AllOf(
+              Each(AtJsonPtr(
+                  "/url",
+                  Conditional(
+                      GetParam().withConsolePolyfill,
+                      AnyOf("script.js", "prelude.js"),
+                      "script.js"))),
+              // A relatively weak assertion: we expect at least one frame tying
+              // the call to the `console.log` line.
+              Contains(AllOf(
+                  AtJsonPtr("/functionName", "global"),
+                  AtJsonPtr("/url", "script.js"),
+                  AtJsonPtr("/lineNumber", 1),
+                  AtJsonPtr("/scriptId", ScriptIdMapsTo("script.js"))))))));
+  eval(R"( // line 0
+    console.log('hello'); // line 1
+    //# sourceURL=script.js
+  )");
+}
+
 static const auto paramValues = testing::Values(
     Params{
         .withConsolePolyfill = true,

packages/react-native/ReactCommon/jsinspector-modern/tests/InspectorMocks.h

@@ -147,6 +147,11 @@ class MockRuntimeTargetDelegate : public RuntimeTargetDelegate {
       (jsi::Runtime & runtime, ConsoleMessage message),
       (override));
   MOCK_METHOD(bool, supportsConsole, (), (override, const));
+  MOCK_METHOD(
+      std::unique_ptr<StackTrace>,
+      captureStackTrace,
+      (jsi::Runtime & runtime, size_t framesToSkip),
+      (override));
 };
 
 class MockRuntimeAgentDelegate : public RuntimeAgentDelegate {

packages/react-native/ReactCommon/jsinspector-modern/tests/prelude.js.h

@@ -632,4 +632,5 @@ if (global.nativeLoggingHook) {
     enumerable: false,
   });
 }})(globalThis, true)
+//# sourceURL=prelude.js
 )___";