Merge remote-tracking branch 'couchbase/unstable' into HEAD

http: //ci-eventing.northscale.in/eventing-09.02.2021-10.29.pass.html
Change-Id: Ie6af89ee90a9b13b8abb2107355c07d068c1fecb

features/include/exceptioninsight.h

@@ -0,0 +1,48 @@
+#ifndef _EVENTING_EXCEPTIONINSIGHT
+#define _EVENTING_EXCEPTIONINSIGHT
+
+#include <chrono>
+#include <map>
+#include <mutex>
+#include <string>
+#include <v8.h>
+
+#include "utils.h"
+#include "crc64.h"
+
+struct ExceptionInfoEntry {
+  ExceptionInfoEntry();
+
+  uint32_t count_;
+  ExceptionInfo exception_info_;
+};
+
+class ExceptionInsight {
+public:
+  explicit ExceptionInsight(v8::Isolate *isolate);
+
+  void Setup(const std::string &function_name);
+
+  void AccumulateException(v8::TryCatch &);
+
+  void AccumulateAndClear(ExceptionInsight &from);
+  void LogExceptionSummary(ExceptionInsight &summary);
+
+  static ExceptionInsight &Get(v8::Isolate *isolate);
+
+private:
+  ExceptionInsight(const ExceptionInsight &) = delete;
+  ExceptionInsight &operator=(const ExceptionInsight &) = delete;
+
+  void InitStartTime();
+
+  std::mutex lock_;
+  std::string function_name_;
+  char start_time_[26];
+
+  std::map<uint64_t, ExceptionInfoEntry> entries_;
+
+  v8::Isolate *isolate_;
+};
+
+#endif

features/include/isolate_data.h

@@ -28,6 +28,7 @@ class CurlRequestBuilder;
 class CurlResponseBuilder;
 class Communicator;
 class CodeInsight;
+class ExceptionInsight;
 struct CurlCodex;
 struct LanguageCompatibility;
 class BucketOps;
@@ -70,6 +71,7 @@ struct IsolateData {
   BucketOps *bucket_ops{nullptr};
   std::mutex termination_lock_;
   bool is_executing_{false};
+  ExceptionInsight *exception_insight{nullptr};
 };
 
 inline IsolateData *UnwrapData(v8::Isolate *isolate) {

features/include/utils.h

@@ -117,6 +117,15 @@ struct ConnStrInfo {
   std::string conn_str;
 };
 
+struct ExceptionInfo {
+
+  std::string exception;
+  uint32_t line;
+  std::string file;
+  std::string srcLine;
+  std::string stack;
+};
+
 class Utils {
 public:
   Utils(v8::Isolate *isolate, const v8::Local<v8::Context> &context);
@@ -202,6 +211,9 @@ std::string GetTranspilerSrc();
 std::string ExceptionString(v8::Isolate *isolate,
                             v8::Local<v8::Context> &context,
                             v8::TryCatch *try_catch);
+ExceptionInfo GetExceptionInfo(v8::Isolate *isolate,
+                            v8::Local<v8::Context> &context,
+                            v8::TryCatch *try_catch);
 
 CompilationInfo BuildCompileInfo(v8::Isolate *isolate,
                                  v8::Local<v8::Context> &context,

features/src/exceptioninsight.cc

@@ -0,0 +1,110 @@
+#include <chrono>
+#include <iomanip>
+#include <map>
+#include <mutex>
+#include <sstream>
+#include <string>
+#include <v8.h>
+#include <nlohmann/json.hpp>
+
+#include "exceptioninsight.h"
+#include "isolate_data.h"
+
+#include "log.h"
+#include "utils.h"
+
+void ExceptionInsight::AccumulateException(v8::TryCatch &try_catch) {
+
+  auto context = isolate_->GetCurrentContext();
+  auto exception_info = GetExceptionInfo(isolate_, context, &try_catch);
+
+  // compute a hash for the exception-info to identify duplicates:
+  // The field 'stack' contains the exception as well as the stack-track and
+  // seems to be the right candidate to check for distinct exceptions.
+  uint64_t crc = crc64_iso.Checksum(reinterpret_cast<const uint8_t *>(exception_info.stack.c_str()),
+    exception_info.stack.length());
+
+  {
+    std::lock_guard<std::mutex> lock(lock_);
+    auto &entry = this->entries_[crc];
+
+    if (entry.count_ == 0) { // capture first occurrance of the exception
+      entry.exception_info_ = exception_info;
+      entry.count_ = 1;
+    } else {
+      entry.count_++;
+    }
+  }
+}
+
+void ExceptionInsight::AccumulateAndClear(ExceptionInsight &from) {
+
+  std::unique_lock<std::mutex> lock_me(lock_, std::defer_lock);
+  std::unique_lock<std::mutex> lock_from(from.lock_, std::defer_lock);
+  std::lock(lock_me, lock_from);
+
+  // Merge all exceptions from 'from' into the current ExceptionInsight instance,
+  // either adding new ones in, or incrementing counts of known ones.
+  for (auto const& iter : from.entries_)
+  {
+    auto &entry = this->entries_[iter.first];
+
+    if (entry.count_ == 0) { // got a new one not in this instance yet.
+      entry.exception_info_ = iter.second.exception_info_;
+      entry.count_ = iter.second.count_;
+    } else {
+      entry.count_ += iter.second.count_;
+    }
+  }
+
+  // re-init the 'from' instance to capture exceptions for the next period of time.
+  from.entries_.clear();
+  from.InitStartTime();
+}
+
+void ExceptionInsight::LogExceptionSummary(ExceptionInsight &exception_insight) {
+
+    std::lock_guard<std::mutex> guard(exception_insight.lock_);
+
+    for (auto const& iter : exception_insight.entries_)
+    {
+      nlohmann::json exceptionInfo;
+
+      exceptionInfo["since"] = exception_insight.start_time_;
+      exceptionInfo["count"] = iter.second.count_;
+      exceptionInfo["exception"] = iter.second.exception_info_.exception;
+      exceptionInfo["file"] = iter.second.exception_info_.file;
+      exceptionInfo["line"] = iter.second.exception_info_.line;
+      exceptionInfo["srcLine"] = iter.second.exception_info_.srcLine;
+      exceptionInfo["stack"] = iter.second.exception_info_.stack;
+
+      APPLOG << exceptionInfo.dump() << std::endl;
+    }
+}
+
+ExceptionInsight::ExceptionInsight(v8::Isolate *isolate) : isolate_(isolate),
+  entries_(std::map<uint64_t, ExceptionInfoEntry>()) {
+
+    InitStartTime();
+  };
+
+ExceptionInsight &ExceptionInsight::Get(v8::Isolate *isolate) {
+  return *(UnwrapData(isolate)->exception_insight);
+}
+
+void ExceptionInsight::Setup(const std::string &function_name) {
+  std::lock_guard<std::mutex> lock(lock_);
+  function_name_ = function_name;
+}
+
+void ExceptionInsight::InitStartTime() {
+    time_t t = time(NULL);
+    struct tm tmbuf;
+    localtime_r(&t, &tmbuf);
+    asctime_r(&tmbuf, start_time_);
+
+    // don't need the NL char at the end of the time string.
+    start_time_[strlen(start_time_) - 1] = '\0';
+}
+
+ExceptionInfoEntry::ExceptionInfoEntry(): count_(0) {};

features/src/utils.cc

@@ -179,42 +179,75 @@ std::string ConvertToISO8601(std::string timestamp) {
   return buf_s;
 }
 
-// Exception details will be appended to the first argument.
 std::string ExceptionString(v8::Isolate *isolate,
                             v8::Local<v8::Context> &context,
                             v8::TryCatch *try_catch) {
 
   std::ostringstream os;
+
+  ExceptionInfo exception_info = GetExceptionInfo(isolate, context, try_catch);
+
+  // The actual exception
+  if (! exception_info.exception.empty()) {
+
+    os << exception_info.exception;
+    os << " " << std::endl;
+  }
+
+  // and its location
+  if (! exception_info.file.empty()) {
+
+    os << "Location: " << exception_info.file << ":" << exception_info.line << " " << std::endl;
+
+    if (! exception_info.srcLine.empty()) {
+      os << "Code: " << exception_info.srcLine << " " << std::endl;
+    }
+
+    // and stack trace
+    if (! exception_info.stack.empty()) {
+      os << "Stack: " << std::endl << exception_info.stack << " " << std::endl;
+    }
+  }
+
+  return os.str();
+}
+
+ExceptionInfo GetExceptionInfo(v8::Isolate *isolate,
+                            v8::Local<v8::Context> &context,
+                            v8::TryCatch *try_catch) {
+
+  ExceptionInfo exception_info;
   v8::HandleScope handle_scope(isolate);
 
-  // Print exception object
+  // Extract exception object
   auto exception = try_catch->Exception();
   if (!exception.IsEmpty()) {
     // If the exception is of Error type, then call toString() on it
-    os << "Exception: ";
+
     v8::Local<v8::Object> obj;
     v8::Local<v8::Value> fn;
     v8::Local<v8::Value> val;
     if (exception->IsNativeError() &&
         TO_LOCAL(exception->ToObject(context), &obj) &&
         TO_LOCAL(obj->Get(context, v8Str(isolate, "toString")), &fn) &&
         TO_LOCAL(fn.As<v8::Function>()->Call(context, obj, 0, nullptr), &val)) {
-      os << JSONStringify(isolate, val, true).c_str();
+      exception_info.exception = JSONStringify(isolate, val, true);
     } else {
-      os << JSONStringify(isolate, try_catch->Exception(), true).c_str();
+      exception_info.exception = JSONStringify(isolate, try_catch->Exception(), true);
     }
-    os << " " << std::endl;
   }
 
-  // Print exception location details
+  // Extract exception location details
   v8::Handle<v8::Message> message = try_catch->Message();
   if (!message.IsEmpty()) {
-    // Print location
+    // Extract location
     v8::String::Utf8Value file(isolate, message->GetScriptResourceName());
     int line = message->GetLineNumber(context).FromMaybe(0);
-    os << "Location: " << ToCString(file) << ":" << line << " " << std::endl;
 
-    // Print source code
+    exception_info.file = ToCString(file);
+    exception_info.line = message->GetLineNumber(context).FromMaybe(0);
+
+    // Extract source code
     auto maybe_srcline = message->GetSourceLine(context);
     if (!maybe_srcline.IsEmpty()) {
       v8::Local<v8::String> local_srcline;
@@ -223,19 +256,22 @@ std::string ExceptionString(v8::Isolate *isolate,
       std::string srcline = ToCString(sourceline_utf8);
       srcline = std::regex_replace(srcline, std::regex("^\\s+"), "");
       srcline = std::regex_replace(srcline, std::regex("\\s+$"), "");
-      os << "Code: " << ToCString(sourceline_utf8) << " " << std::endl;
+
+      exception_info.srcLine = srcline;
     }
 
-    // Print stack trace
+    // Extract stack trace
     auto maybe_stack = try_catch->StackTrace(context);
     if (!maybe_stack.IsEmpty()) {
       v8::Local<v8::Value> local_stack;
       TO_LOCAL(maybe_stack, &local_stack);
       v8::String::Utf8Value stack_utf8(isolate, local_stack);
-      os << "Stack: " << std::endl << ToCString(stack_utf8) << " " << std::endl;
+
+      exception_info.stack = ToCString(stack_utf8);
     }
   }
-  return os.str();
+
+  return exception_info;
 }
 
 std::vector<std::string> &split(const std::string &s, char delim,

v8_consumer/CMakeLists.txt

@@ -41,6 +41,7 @@ SET(FEATURES_SRC
         ../features/src/utils.cc
         ../features/src/base64.cc
         ../features/src/insight.cc
+        ../features/src/exceptioninsight.cc
         ../features/src/bucket_ops.cc
         ../features/src/bucket_cache.cc
         ../third_party/crc64/crc64.cc

v8_consumer/include/client.h

@@ -84,6 +84,8 @@ class AppWorker {
 
   void EventGenLoop();
 
+  void ExceptionSummaryLogLoop();
+
   static void StopUvLoop(uv_async_t *);
 
   void SendFilterAck(int opcode, int msgtype, int vb_no, int64_t seq_no,
@@ -112,6 +114,9 @@ class AppWorker {
   AppWorker();
   ~AppWorker();
 
+  bool shouldNotLogExceptionSummaryYet() ;
+  void LogExceptionSummary();
+
   std::vector<std::unordered_set<int64_t>>
   PartitionVbuckets(const std::vector<int64_t> &vbuckets) const;
 

v8_consumer/include/v8worker.h

@@ -39,6 +39,7 @@
 #include "commands.h"
 #include "histogram.h"
 #include "insight.h"
+#include "exceptioninsight.h"
 #include "inspector_agent.h"
 #include "isolate_data.h"
 #include "js_exception.h"
@@ -264,6 +265,8 @@ class V8Worker {
 
   CodeInsight &GetInsight();
 
+  ExceptionInsight &GetExceptionInsight();
+
   void EraseVbFilter(int vb_no);
 
   void UpdateBucketopsSeqnoLocked(int vb_no, uint64_t seq_no);