Add logTrace API for Kabuki to log instrumentation events through JS …

…h5vcc API (#2877)

Add a ringbuffer to the watchdog to hold events emitted from logEvent()
API. InstrumentationLog is thread-safe.
LogTrace(snapshot of event log) is added to the violation json when
violation is created.

b/327680765

Change-Id: I73159740487d7e791e8a0238999b5b06f1e2ae47

cobalt/BUILD.gn

@@ -40,6 +40,7 @@ group("gn_all") {
     "//cobalt/renderer/sandbox:scaling_text_sandbox",
     "//cobalt/speech/sandbox:speech_sandbox",
     "//cobalt/ui_navigation/scroll_engine:scroll_engine_tests",
+    "//cobalt/watchdog:watchdog_test",
     "//cobalt/web:web_test",
     "//cobalt/web_animations:web_animations_test",
     "//cobalt/webdriver:webdriver_test",

cobalt/h5vcc/h5vcc_crash_log.cc

@@ -174,5 +174,35 @@ void H5vccCrashLog::SetPersistentSettingWatchdogCrash(bool can_trigger_crash) {
   if (watchdog) watchdog->SetPersistentSettingWatchdogCrash(can_trigger_crash);
 }
 
+bool H5vccCrashLog::LogEvent(const std::string& event) {
+  watchdog::Watchdog* watchdog = watchdog::Watchdog::GetInstance();
+  if (!watchdog) {
+    return false;
+  }
+
+  return watchdog->LogEvent(event);
+}
+
+script::Sequence<std::string> H5vccCrashLog::GetLogTrace() {
+  watchdog::Watchdog* watchdog = watchdog::Watchdog::GetInstance();
+
+  script::Sequence<std::string> sequence;
+  if (watchdog) {
+    std::vector<std::string> logTrace = watchdog->GetLogTrace();
+    for (std::size_t i = 0; i < logTrace.size(); ++i) {
+      sequence.push_back(logTrace[i]);
+    }
+  }
+
+  return sequence;
+}
+
+void H5vccCrashLog::ClearLog() {
+  watchdog::Watchdog* watchdog = watchdog::Watchdog::GetInstance();
+  if (watchdog) {
+    watchdog->ClearLog();
+  }
+}
+
 }  // namespace h5vcc
 }  // namespace cobalt

cobalt/h5vcc/h5vcc_crash_log.h

@@ -59,6 +59,12 @@ class H5vccCrashLog : public script::Wrappable {
 
   void SetPersistentSettingWatchdogCrash(bool can_trigger_crash);
 
+  bool LogEvent(const std::string& event);
+
+  script::Sequence<std::string> GetLogTrace();
+
+  void ClearLog();
+
   DEFINE_WRAPPABLE_TYPE(H5vccCrashLog);
 
  private:

cobalt/h5vcc/h5vcc_crash_log.idl

@@ -108,4 +108,19 @@ interface H5vccCrashLog {
   // Sets a persistent Watchdog setting that determines whether or not a
   // Watchdog violation will trigger a crash.
   void setPersistentSettingWatchdogCrash(boolean can_trigger_crash);
+
+  // Appends a string event to a ring buffer. These log events can be appended
+  // from JS code. When watchdog violation is created, a snapshot of
+  // that buffer is attached to a violation. Identical sequential events
+  // are de-duplicated.
+  // Max event length is 256. Ring buffer size is 128.
+  boolean logEvent(DOMString event);
+
+  // Returns a snapshot (a "logTrace") of ring buffer of log events.
+  // This can be used to read a logTrace at arbitrary moment,
+  // without any violation.
+  sequence<DOMString> getLogTrace();
+
+  // Clears the ring buffer of log events.
+  void clearLog();
 };

cobalt/watchdog/BUILD.gn

@@ -14,6 +14,8 @@
 
 static_library("watchdog") {
   sources = [
+    "instrumentation_log.cc",
+    "instrumentation_log.h",
     "watchdog.cc",
     "watchdog.h",
   ]
@@ -29,7 +31,10 @@ static_library("watchdog") {
 target(gtest_target_type, "watchdog_test") {
   testonly = true
 
-  sources = [ "watchdog_test.cc" ]
+  sources = [
+    "instrumentation_log_test.cc",
+    "watchdog_test.cc",
+  ]
 
   deps = [
     ":watchdog",

cobalt/watchdog/instrumentation_log.cc

@@ -0,0 +1,63 @@
+// Copyright 2024 The Cobalt Authors. All Rights Reserved.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+#include "cobalt/watchdog/instrumentation_log.h"
+
+#include <string>
+#include <vector>
+
+namespace cobalt {
+namespace watchdog {
+
+bool InstrumentationLog::LogEvent(const std::string& event) {
+  if (event.length() > kMaxEventLenBytes) {
+    SB_DLOG(ERROR) << "[Watchdog] Log event exceeds max: " << kMaxEventLenBytes;
+    return false;
+  }
+
+  starboard::ScopedLock scoped_lock(buffer_mutex_);
+  buffer_.SaveToBuffer(event);
+
+  return true;
+}
+
+std::vector<std::string> InstrumentationLog::GetLogTrace() {
+  std::vector<std::string> traceEvents;
+
+  starboard::ScopedLock scoped_lock(buffer_mutex_);
+  for (auto it = buffer_.Begin(); it; ++it) {
+    traceEvents.push_back(**it);
+  }
+
+  return traceEvents;
+}
+
+base::Value InstrumentationLog::GetLogTraceAsValue() {
+  base::Value log_trace_value = base::Value(base::Value::Type::LIST);
+
+  starboard::ScopedLock scoped_lock(buffer_mutex_);
+  for (auto it = buffer_.Begin(); it; ++it) {
+    log_trace_value.GetList().emplace_back(**it);
+  }
+
+  return log_trace_value;
+}
+
+void InstrumentationLog::ClearLog() {
+  starboard::ScopedLock scoped_lock(buffer_mutex_);
+  buffer_.Clear();
+}
+
+}  // namespace watchdog
+}  // namespace cobalt

cobalt/watchdog/instrumentation_log.h

@@ -0,0 +1,59 @@
+// Copyright 2024 The Cobalt Authors. All Rights Reserved.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+#ifndef COBALT_WATCHDOG_INSTRUMENTATION_LOG_H_
+#define COBALT_WATCHDOG_INSTRUMENTATION_LOG_H_
+
+#include <string>
+#include <vector>
+
+#include "base/containers/ring_buffer.h"
+#include "base/values.h"
+#include "starboard/common/mutex.h"
+
+namespace cobalt {
+namespace watchdog {
+
+constexpr int kBufferSize = 128;
+constexpr int kMaxEventLenBytes = 256;
+
+// Wrapper class on top of base::RingBuffer for tracking log events emitted
+// through logEvent() h5vcc API. There's an optimization: identical sequential
+// events added back to back are folded into single event.
+class InstrumentationLog {
+ public:
+  // Append a single event to the end of the buffer.
+  bool LogEvent(const std::string& event);
+
+  // Returns a snapshot of the ring buffer.
+  // Vector of kBufferSize strings at max.
+  std::vector<std::string> GetLogTrace();
+
+  // Same as GetLogTrace() but converted to base::Value for json serialization.
+  base::Value GetLogTraceAsValue();
+
+  // Empty the ring buffer.
+  void ClearLog();
+
+ private:
+  base::RingBuffer<std::string, kBufferSize> buffer_;
+
+  // Mutex to guard buffer operations. E.g. LogEvent() called from h5vcc API
+  // handler and getLogTrace() called from watchdog monitoring thread.
+  starboard::Mutex buffer_mutex_;
+};
+
+}  // namespace watchdog
+}  // namespace cobalt
+#endif  // COBALT_WATCHDOG_INSTRUMENTATION_LOG_H_

cobalt/watchdog/instrumentation_log_test.cc

@@ -0,0 +1,122 @@
+// Copyright 2024 The Cobalt Authors. All Rights Reserved.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+#include "cobalt/watchdog//instrumentation_log.h"
+
+#include <set>
+#include <vector>
+
+#include "base/json/json_reader.h"
+#include "base/json/json_writer.h"
+#include "starboard/common/file.h"
+#include "testing/gtest/include/gtest/gtest.h"
+
+namespace cobalt {
+namespace watchdog {
+
+class InstrumentationLogTest : public testing::Test {
+ protected:
+  InstrumentationLog* instrumentation_log_;
+};
+
+TEST_F(InstrumentationLogTest, CanCallLogEvent) {
+  InstrumentationLog log;
+  log.LogEvent("abc");
+
+  ASSERT_EQ(log.GetLogTrace().size(), 1);
+}
+
+TEST_F(InstrumentationLogTest, LogEventReturnsFalseOnMaxLenExceed) {
+  InstrumentationLog log;
+
+  std::string maxLenEvent(kMaxEventLenBytes, 'a');
+  ASSERT_TRUE(log.LogEvent(maxLenEvent));
+
+  std::string exceedingLenEvent(kMaxEventLenBytes + 1, 'a');
+  ASSERT_FALSE(log.LogEvent(exceedingLenEvent));
+}
+
+TEST_F(InstrumentationLogTest, GetLogTraceReturnsEventsInOrder) {
+  InstrumentationLog log;
+
+  for (int i = 0; i < kBufferSize; i++) {
+    log.LogEvent(std::to_string(i));
+  }
+
+  log.LogEvent("1");
+  log.LogEvent("2");
+  log.LogEvent("3");
+  log.LogEvent("4");
+  log.LogEvent("5");
+
+  ASSERT_EQ(log.GetLogTrace().at(kBufferSize - 1 - 4), "1");
+  ASSERT_EQ(log.GetLogTrace().at(kBufferSize - 1 - 3), "2");
+  ASSERT_EQ(log.GetLogTrace().at(kBufferSize - 1 - 2), "3");
+  ASSERT_EQ(log.GetLogTrace().at(kBufferSize - 1 - 1), "4");
+  ASSERT_EQ(log.GetLogTrace().at(kBufferSize - 1), "5");
+}
+
+TEST_F(InstrumentationLogTest, GetLogTraceCanReturnDuplicateEvents) {
+  InstrumentationLog log;
+
+  log.LogEvent("1");
+  log.LogEvent("1");
+  log.LogEvent("1");
+
+  ASSERT_EQ(log.GetLogTrace().at(0), "1");
+  ASSERT_EQ(log.GetLogTrace().at(1), "1");
+  ASSERT_EQ(log.GetLogTrace().at(2), "1");
+}
+
+TEST_F(InstrumentationLogTest, CanGetEmptyTraceAsValue) {
+  InstrumentationLog log;
+
+  ASSERT_EQ(log.GetLogTraceAsValue().GetList().size(), 0);
+}
+
+TEST_F(InstrumentationLogTest, CanGetLogTraceAsValue) {
+  InstrumentationLog log;
+
+  log.LogEvent("1");
+  log.LogEvent("2");
+  log.LogEvent("3");
+
+  ASSERT_EQ(log.GetLogTraceAsValue().GetList().at(0).GetString(), "1");
+  ASSERT_EQ(log.GetLogTraceAsValue().GetList().at(1).GetString(), "2");
+  ASSERT_EQ(log.GetLogTraceAsValue().GetList().at(2).GetString(), "3");
+}
+
+TEST_F(InstrumentationLogTest, CanClearLog) {
+  InstrumentationLog log;
+
+  log.LogEvent("1");
+  log.LogEvent("2");
+  log.LogEvent("3");
+
+  ASSERT_EQ(log.GetLogTrace().size(), 3);
+
+  log.ClearLog();
+  ASSERT_EQ(log.GetLogTrace().size(), 0);
+}
+
+TEST_F(InstrumentationLogTest, CanClearEmptyLog) {
+  InstrumentationLog log;
+  ASSERT_EQ(log.GetLogTrace().size(), 0);
+
+  log.ClearLog();
+  ASSERT_EQ(log.GetLogTrace().size(), 0);
+}
+
+}  // namespace watchdog
+}  // namespace cobalt