From e6f3178ef3e1b4af381481d4b96a66c2be447f52 Mon Sep 17 00:00:00 2001 From: Matt Blagden Date: Mon, 26 Feb 2024 09:58:30 -0800 Subject: [PATCH] Buffer console messages Summary: Buffer console messages. When messages are generated, add them to the console message storage. When a new client enables the `Runtime` domain, send any buffered messages. Reviewed By: dannysu Differential Revision: D54028594 fbshipit-source-id: 4f0bf6581c23a3813a460e2eb5cd0c65b74c912c --- API/hermes/cdp/CDPAgent.cpp | 3 ++ API/hermes/cdp/CDPDebugAPI.cpp | 1 + API/hermes/cdp/ConsoleMessage.cpp | 7 +++ API/hermes/cdp/ConsoleMessage.h | 2 + API/hermes/cdp/RuntimeDomainAgent.cpp | 28 ++++++++++ API/hermes/cdp/RuntimeDomainAgent.h | 2 + unittests/API/CDPAgentTest.cpp | 78 +++++++++++++++++++++++++++ 7 files changed, 121 insertions(+) diff --git a/API/hermes/cdp/CDPAgent.cpp b/API/hermes/cdp/CDPAgent.cpp index b127133be14..a11a5e58e5d 100644 --- a/API/hermes/cdp/CDPAgent.cpp +++ b/API/hermes/cdp/CDPAgent.cpp @@ -70,6 +70,7 @@ class CDPAgentImpl { int32_t executionContextID_; HermesRuntime &runtime_; debugger::AsyncDebuggerAPI &asyncDebuggerAPI_; + ConsoleMessageStorage &consoleMessageStorage_; ConsoleMessageDispatcher &consoleMessageDispatcher_; /// Callback function for sending CDP response back. Same as the one in @@ -167,6 +168,7 @@ CDPAgentImpl::DomainAgents::DomainAgents( : executionContextID_(executionContextID), runtime_(cdpDebugAPI.runtime()), asyncDebuggerAPI_(cdpDebugAPI.asyncDebuggerAPI()), + consoleMessageStorage_(cdpDebugAPI.consoleMessageStorage_), consoleMessageDispatcher_(cdpDebugAPI.consoleMessageDispatcher_), messageCallback_(std::move(messageCallback)), objTable_(std::make_shared()) {} @@ -183,6 +185,7 @@ void CDPAgentImpl::DomainAgents::initialize() { runtime_, messageCallback_, objTable_, + consoleMessageStorage_, consoleMessageDispatcher_); profilerAgent_ = std::make_unique( executionContextID_, runtime_, messageCallback_, objTable_); diff --git a/API/hermes/cdp/CDPDebugAPI.cpp b/API/hermes/cdp/CDPDebugAPI.cpp index be9e80ea093..b5a34f77c69 100644 --- a/API/hermes/cdp/CDPDebugAPI.cpp +++ b/API/hermes/cdp/CDPDebugAPI.cpp @@ -31,6 +31,7 @@ CDPDebugAPI::CDPDebugAPI(HermesRuntime &runtime, size_t maxCachedMessages) void CDPDebugAPI::addConsoleMessage(ConsoleMessage message) { consoleMessageDispatcher_.deliverMessage(message); + consoleMessageStorage_.addMessage(std::move(message)); } } // namespace cdp diff --git a/API/hermes/cdp/ConsoleMessage.cpp b/API/hermes/cdp/ConsoleMessage.cpp index 917ef5b4f81..1f98e104d7d 100644 --- a/API/hermes/cdp/ConsoleMessage.cpp +++ b/API/hermes/cdp/ConsoleMessage.cpp @@ -46,6 +46,13 @@ size_t ConsoleMessageStorage::discarded() const { return numConsoleMessagesDiscardedFromCache_; } +std::optional ConsoleMessageStorage::oldestTimestamp() const { + if (consoleMessageCache_.size() == 0) { + return std::nullopt; + } + return consoleMessageCache_.front().timestamp; +} + } // namespace cdp } // namespace hermes } // namespace facebook diff --git a/API/hermes/cdp/ConsoleMessage.h b/API/hermes/cdp/ConsoleMessage.h index 2d4257be2bd..b1c00eac53f 100644 --- a/API/hermes/cdp/ConsoleMessage.h +++ b/API/hermes/cdp/ConsoleMessage.h @@ -8,6 +8,7 @@ #ifndef HERMES_CDP_CDPCONSOLEMESSAGESTORAGE_H #define HERMES_CDP_CDPCONSOLEMESSAGESTORAGE_H +#include #include #include @@ -62,6 +63,7 @@ class ConsoleMessageStorage { const std::deque &messages() const; size_t discarded() const; + std::optional oldestTimestamp() const; private: /// Maximum number of messages to cache. diff --git a/API/hermes/cdp/RuntimeDomainAgent.cpp b/API/hermes/cdp/RuntimeDomainAgent.cpp index 3ecc3c97a84..446ae250b1d 100644 --- a/API/hermes/cdp/RuntimeDomainAgent.cpp +++ b/API/hermes/cdp/RuntimeDomainAgent.cpp @@ -256,12 +256,14 @@ RuntimeDomainAgent::RuntimeDomainAgent( HermesRuntime &runtime, SynchronizedOutboundCallback messageCallback, std::shared_ptr objTable, + ConsoleMessageStorage &consoleMessageStorage, ConsoleMessageDispatcher &consoleMessageDispatcher) : DomainAgent( executionContextID, std::move(messageCallback), std::move(objTable)), runtime_(runtime), + consoleMessageStorage_(consoleMessageStorage), consoleMessageDispatcher_(consoleMessageDispatcher), enabled_(false) { consoleMessageRegistration_ = consoleMessageDispatcher_.subscribe( @@ -287,6 +289,32 @@ void RuntimeDomainAgent::enable(const m::runtime::EnableRequest &req) { // Enable enabled_ = true; sendResponseToClient(m::makeOkResponse(req.id)); + + // Send any buffered console messages. + size_t numConsoleMessagesDiscardedFromCache = + consoleMessageStorage_.discarded(); + + if (numConsoleMessagesDiscardedFromCache != 0) { + std::ostringstream oss; + oss << "Only limited number of console messages can be cached. " + << numConsoleMessagesDiscardedFromCache + << (numConsoleMessagesDiscardedFromCache == 1 ? " message was" + : " messages were") + + << " discarded at the beginning."; + jsi::Value arg = jsi::String::createFromAscii(runtime_, oss.str()); + std::vector args; + args.push_back(std::move(arg)); + + consoleAPICalled(ConsoleMessage( + *consoleMessageStorage_.oldestTimestamp() - 0.1, + ConsoleAPIType::kWarning, + std::move(args))); + } + + for (auto &message : consoleMessageStorage_.messages()) { + consoleAPICalled(message); + } } void RuntimeDomainAgent::disable(const m::runtime::DisableRequest &req) { diff --git a/API/hermes/cdp/RuntimeDomainAgent.h b/API/hermes/cdp/RuntimeDomainAgent.h index a58d56818e2..e644fe0db51 100644 --- a/API/hermes/cdp/RuntimeDomainAgent.h +++ b/API/hermes/cdp/RuntimeDomainAgent.h @@ -28,6 +28,7 @@ class RuntimeDomainAgent : public DomainAgent { HermesRuntime &runtime, SynchronizedOutboundCallback messageCallback, std::shared_ptr objTable, + ConsoleMessageStorage &consoleMessageStorage, ConsoleMessageDispatcher &consoleMessageDispatcher); ~RuntimeDomainAgent(); @@ -66,6 +67,7 @@ class RuntimeDomainAgent : public DomainAgent { bool generatePreview); HermesRuntime &runtime_; + ConsoleMessageStorage &consoleMessageStorage_; ConsoleMessageDispatcher &consoleMessageDispatcher_; /// Whether Runtime.enable was received and wasn't disabled by receiving diff --git a/unittests/API/CDPAgentTest.cpp b/unittests/API/CDPAgentTest.cpp index 2ebaccd4a58..15caf952715 100644 --- a/unittests/API/CDPAgentTest.cpp +++ b/unittests/API/CDPAgentTest.cpp @@ -2287,4 +2287,82 @@ TEST_F(CDPAgentTest, ConsoleLog) { {"__proto__", PropInfo("object")}}); } +TEST_F(CDPAgentTest, ConsoleBuffer) { + int msgId = 1; + + constexpr int kExpectedMaxBufferSize = 1000; + constexpr int kNumLogsToTest = kExpectedMaxBufferSize * 2; + + // Generate console messages on the runtime thread + waitFor([this, kNumLogsToTest](auto promise) { + runtimeThread_->add([this, promise, kNumLogsToTest]() { + for (int i = 0; i < kNumLogsToTest; i++) { + jsi::Value value = + jsi::String::createFromUtf8(*runtime_, std::to_string(i)); + std::vector args; + args.push_back(std::move(value)); + cdpDebugAPI_->addConsoleMessage( + ConsoleMessage{0.0, ConsoleAPIType::kLog, std::move(args)}); + } + + promise->set_value(true); + }); + }); + + bool receivedWarning = false; + std::array received; + + // Test for repeated connection by sending Runtime.enable multiple times. It's + // expected that the message cache is always kept around and provided to the + // frontend each time. + for (int numConnect = 0; numConnect < 2; numConnect++) { + receivedWarning = false; + received.fill(false); + + sendAndCheckResponse("Runtime.enable", msgId++); + + // Loop for 1 iteration more than kExpectedMaxBufferSize because there is a + // warning message given when buffer is exceeded + for (size_t i = 0; i < kExpectedMaxBufferSize + 1; i++) { + auto note = expectNotification("Runtime.consoleAPICalled"); + EXPECT_EQ( + jsonScope_.getString(note, {"params", "args", "0", "type"}), + "string"); + + size_t argCount = jsonScope_.getArray(note, {"params", "args"})->size(); + EXPECT_EQ(argCount, 1); + + std::string type = jsonScope_.getString(note, {"params", "type"}); + std::string value = + jsonScope_.getString(note, {"params", "args", "0", "value"}); + try { + // Verify that the latest kExpectedMaxBufferSize number of logs are + // emitted + int nthLog = std::stoi(value); + EXPECT_GT(nthLog, kExpectedMaxBufferSize - 1); + EXPECT_LT(nthLog, kNumLogsToTest); + EXPECT_EQ(type, "log"); + received[nthLog % kExpectedMaxBufferSize] = true; + } catch (const std::exception &e) { + EXPECT_EQ(type, "warning"); + EXPECT_NE(value.find("discarded"), std::string::npos); + receivedWarning = true; + } + } + + // Make sure no more log messages arrive + expectNothing(); + + // Ensure everything was expected + for (size_t i = 0; i < kExpectedMaxBufferSize; i++) { + EXPECT_TRUE(received[i]); + } + EXPECT_TRUE(receivedWarning); + + // Disable the runtime so it can be enabled again in the next iteration of + // the loop + sendAndCheckResponse("Runtime.disable", msgId++); + } +} + #endif // HERMES_ENABLE_DEBUGGER