Add args and copy support to V8 tracing controller.

BUG=v8:4561

Review-Url: https://codereview.chromium.org/2190973003
Cr-Commit-Position: refs/heads/master@{#38255}

BUILD.gn

@@ -2121,6 +2121,7 @@ v8_source_set("v8_libbase") {
 
 v8_source_set("v8_libplatform") {
   sources = [
+    "//base/trace_event/common/trace_event_common.h",
     "include/libplatform/libplatform.h",
     "include/libplatform/v8-tracing.h",
     "src/libplatform/default-platform.cc",

include/libplatform/v8-tracing.h

@@ -13,9 +13,21 @@ namespace v8 {
 namespace platform {
 namespace tracing {
 
+const int kTraceMaxNumArgs = 2;
+
 class TraceObject {
  public:
+  union ArgValue {
+    bool as_bool;
+    uint64_t as_uint;
+    int64_t as_int;
+    double as_double;
+    const void* as_pointer;
+    const char* as_string;
+  };
+
   TraceObject() {}
+  ~TraceObject();
   void Initialize(char phase, const uint8_t* category_enabled_flag,
                   const char* name, const char* scope, uint64_t id,
                   uint64_t bind_id, int num_args, const char** arg_names,
@@ -40,6 +52,10 @@ class TraceObject {
   const char* scope() const { return scope_; }
   uint64_t id() const { return id_; }
   uint64_t bind_id() const { return bind_id_; }
+  int num_args() const { return num_args_; }
+  const char** arg_names() { return arg_names_; }
+  uint8_t* arg_types() { return arg_types_; }
+  ArgValue* arg_values() { return arg_values_; }
   unsigned int flags() const { return flags_; }
   int64_t ts() { return ts_; }
   int64_t tts() { return tts_; }
@@ -56,12 +72,15 @@ class TraceObject {
   uint64_t id_;
   uint64_t bind_id_;
   int num_args_;
+  const char* arg_names_[kTraceMaxNumArgs];
+  uint8_t arg_types_[kTraceMaxNumArgs];
+  ArgValue arg_values_[kTraceMaxNumArgs];
+  char* parameter_copy_storage_ = nullptr;
   unsigned int flags_;
   int64_t ts_;
   int64_t tts_;
   uint64_t duration_;
   uint64_t cpu_duration_;
-  // TODO(fmeawad): Add args support.
 
   // Disallow copy and assign
   TraceObject(const TraceObject&) = delete;

src/libplatform/tracing/trace-object.cc

@@ -4,6 +4,7 @@
 
 #include "include/libplatform/v8-tracing.h"
 
+#include "base/trace_event/common/trace_event_common.h"
 #include "src/base/platform/platform.h"
 #include "src/base/platform/time.h"
 
@@ -11,6 +12,24 @@ namespace v8 {
 namespace platform {
 namespace tracing {
 
+// We perform checks for NULL strings since it is possible that a string arg
+// value is NULL.
+V8_INLINE static size_t GetAllocLength(const char* str) {
+  return str ? strlen(str) + 1 : 0;
+}
+
+// Copies |*member| into |*buffer|, sets |*member| to point to this new
+// location, and then advances |*buffer| by the amount written.
+V8_INLINE static void CopyTraceObjectParameter(char** buffer,
+                                               const char** member,
+                                               const char* end) {
+  if (*member) {
+    strncpy(*buffer, *member, end - *buffer);
+    *member = *buffer;
+    *buffer += strlen(*member) + 1;
+  }
+}
+
 void TraceObject::Initialize(char phase, const uint8_t* category_enabled_flag,
                              const char* name, const char* scope, uint64_t id,
                              uint64_t bind_id, int num_args,
@@ -24,14 +43,62 @@ void TraceObject::Initialize(char phase, const uint8_t* category_enabled_flag,
   scope_ = scope;
   id_ = id;
   bind_id_ = bind_id;
-  num_args_ = num_args;
   flags_ = flags;
   ts_ = base::TimeTicks::HighResolutionNow().ToInternalValue();
   tts_ = base::ThreadTicks::Now().ToInternalValue();
   duration_ = 0;
   cpu_duration_ = 0;
+
+  // Clamp num_args since it may have been set by a third-party library.
+  num_args_ = (num_args > kTraceMaxNumArgs) ? kTraceMaxNumArgs : num_args;
+  for (int i = 0; i < num_args_; ++i) {
+    arg_names_[i] = arg_names[i];
+    arg_values_[i].as_uint = arg_values[i];
+    arg_types_[i] = arg_types[i];
+  }
+
+  bool copy = !!(flags & TRACE_EVENT_FLAG_COPY);
+  // Allocate a long string to fit all string copies.
+  size_t alloc_size = 0;
+  if (copy) {
+    alloc_size += GetAllocLength(name) + GetAllocLength(scope);
+    for (int i = 0; i < num_args_; ++i) {
+      alloc_size += GetAllocLength(arg_names_[i]);
+      if (arg_types_[i] == TRACE_VALUE_TYPE_STRING)
+        arg_types_[i] = TRACE_VALUE_TYPE_COPY_STRING;
+    }
+  }
+
+  bool arg_is_copy[kTraceMaxNumArgs];
+  for (int i = 0; i < num_args_; ++i) {
+    // We only take a copy of arg_vals if they are of type COPY_STRING.
+    arg_is_copy[i] = (arg_types_[i] == TRACE_VALUE_TYPE_COPY_STRING);
+    if (arg_is_copy[i]) alloc_size += GetAllocLength(arg_values_[i].as_string);
+  }
+
+  if (alloc_size) {
+    // Since TraceObject can be initialized multiple times, we might need
+    // to free old memory.
+    delete[] parameter_copy_storage_;
+    char* ptr = parameter_copy_storage_ = new char[alloc_size];
+    const char* end = ptr + alloc_size;
+    if (copy) {
+      CopyTraceObjectParameter(&ptr, &name_, end);
+      CopyTraceObjectParameter(&ptr, &scope_, end);
+      for (int i = 0; i < num_args_; ++i) {
+        CopyTraceObjectParameter(&ptr, &arg_names_[i], end);
+      }
+    }
+    for (int i = 0; i < num_args_; ++i) {
+      if (arg_is_copy[i]) {
+        CopyTraceObjectParameter(&ptr, &arg_values_[i].as_string, end);
+      }
+    }
+  }
 }
 
+TraceObject::~TraceObject() { delete[] parameter_copy_storage_; }
+
 void TraceObject::UpdateDuration() {
   duration_ = base::TimeTicks::HighResolutionNow().ToInternalValue() - ts_;
   cpu_duration_ = base::ThreadTicks::Now().ToInternalValue() - tts_;

src/libplatform/tracing/trace-writer.cc

@@ -4,12 +4,85 @@
 
 #include "src/libplatform/tracing/trace-writer.h"
 
+#include <cmath>
+
+#include "base/trace_event/common/trace_event_common.h"
 #include "src/base/platform/platform.h"
 
 namespace v8 {
 namespace platform {
 namespace tracing {
 
+// Currently we do not support JSON-escaping strings in trace arguments.
+// Thus we perform an IsJSONString() check before writing any string argument.
+// In particular, this means strings cannot have control characters or " or \.
+V8_INLINE static bool IsJSONString(const char* str) {
+  size_t len = strlen(str);
+  for (size_t i = 0; i < len; ++i) {
+    if (iscntrl(str[i]) || str[i] == '\"' || str[i] == '\\') {
+      return false;
+    }
+  }
+  return true;
+}
+
+void JSONTraceWriter::AppendArgValue(uint8_t type,
+                                     TraceObject::ArgValue value) {
+  switch (type) {
+    case TRACE_VALUE_TYPE_BOOL:
+      stream_ << (value.as_bool ? "true" : "false");
+      break;
+    case TRACE_VALUE_TYPE_UINT:
+      stream_ << value.as_uint;
+      break;
+    case TRACE_VALUE_TYPE_INT:
+      stream_ << value.as_int;
+      break;
+    case TRACE_VALUE_TYPE_DOUBLE: {
+      std::string real;
+      double val = value.as_double;
+      if (std::isfinite(val)) {
+        std::ostringstream convert_stream;
+        convert_stream << val;
+        real = convert_stream.str();
+        // Ensure that the number has a .0 if there's no decimal or 'e'.  This
+        // makes sure that when we read the JSON back, it's interpreted as a
+        // real rather than an int.
+        if (real.find('.') == std::string::npos &&
+            real.find('e') == std::string::npos &&
+            real.find('E') == std::string::npos) {
+          real += ".0";
+        }
+      } else if (std::isnan(val)) {
+        // The JSON spec doesn't allow NaN and Infinity (since these are
+        // objects in EcmaScript).  Use strings instead.
+        real = "\"NaN\"";
+      } else if (val < 0) {
+        real = "\"-Infinity\"";
+      } else {
+        real = "\"Infinity\"";
+      }
+      stream_ << real;
+      break;
+    }
+    case TRACE_VALUE_TYPE_POINTER:
+      // JSON only supports double and int numbers.
+      // So as not to lose bits from a 64-bit pointer, output as a hex string.
+      stream_ << "\"" << value.as_pointer << "\"";
+      break;
+    case TRACE_VALUE_TYPE_STRING:
+    case TRACE_VALUE_TYPE_COPY_STRING:
+      // Strings are currently not JSON-escaped, so we need to perform a check
+      // to see if they are valid JSON strings.
+      CHECK(value.as_string == nullptr || IsJSONString(value.as_string));
+      stream_ << "\"" << (value.as_string ? value.as_string : "NULL") << "\"";
+      break;
+    default:
+      UNREACHABLE();
+      break;
+  }
+}
+
 JSONTraceWriter::JSONTraceWriter(std::ostream& stream) : stream_(stream) {
   stream_ << "{\"traceEvents\":[";
 }
@@ -19,7 +92,6 @@ JSONTraceWriter::~JSONTraceWriter() { stream_ << "]}"; }
 void JSONTraceWriter::AppendTraceEvent(TraceObject* trace_event) {
   if (append_comma_) stream_ << ",";
   append_comma_ = true;
-  if (trace_event->scope() == NULL) {
   stream_ << "{\"pid\":" << trace_event->pid()
           << ",\"tid\":" << trace_event->tid()
           << ",\"ts\":" << trace_event->ts()
@@ -28,21 +100,25 @@ void JSONTraceWriter::AppendTraceEvent(TraceObject* trace_event) {
           << TracingController::GetCategoryGroupName(
                  trace_event->category_enabled_flag())
           << "\",\"name\":\"" << trace_event->name()
-            << "\",\"args\":{},\"dur\":" << trace_event->duration()
-            << ",\"tdur\":" << trace_event->cpu_duration() << "}";
-  } else {
-    stream_ << "{\"pid\":" << trace_event->pid()
-            << ",\"tid\":" << trace_event->tid()
-            << ",\"ts\":" << trace_event->ts()
-            << ",\"tts\":" << trace_event->tts() << ",\"ph\":\""
-            << trace_event->phase() << "\",\"cat\":\""
-            << TracingController::GetCategoryGroupName(
-                   trace_event->category_enabled_flag())
-            << "\",\"name\":\"" << trace_event->name() << "\",\"scope\":\""
-            << trace_event->scope()
-            << "\",\"args\":{},\"dur\":" << trace_event->duration()
-            << ",\"tdur\":" << trace_event->cpu_duration() << "}";
+          << "\",\"dur\":" << trace_event->duration()
+          << ",\"tdur\":" << trace_event->cpu_duration();
+  if (trace_event->flags() & TRACE_EVENT_FLAG_HAS_ID) {
+    if (trace_event->scope() != nullptr) {
+      stream_ << ",\"scope\":\"" << trace_event->scope() << "\"";
+    }
+    // So as not to lose bits from a 64-bit integer, output as a hex string.
+    stream_ << ",\"id\":\"0x" << std::hex << trace_event->id() << "\"";
+  }
+  stream_ << ",\"args\":{";
+  const char** arg_names = trace_event->arg_names();
+  const uint8_t* arg_types = trace_event->arg_types();
+  TraceObject::ArgValue* arg_values = trace_event->arg_values();
+  for (int i = 0; i < trace_event->num_args(); ++i) {
+    if (i > 0) stream_ << ",";
+    stream_ << "\"" << arg_names[i] << "\":";
+    AppendArgValue(arg_types[i], arg_values[i]);
   }
+  stream_ << "}}";
   // TODO(fmeawad): Add support for Flow Events.
 }
 

src/libplatform/tracing/trace-writer.h

@@ -19,6 +19,8 @@ class JSONTraceWriter : public TraceWriter {
   void Flush() override;
 
  private:
+  void AppendArgValue(uint8_t type, TraceObject::ArgValue value);
+
   std::ostream& stream_;
   bool append_comma_ = false;
 };

test/cctest/libplatform/test-tracing.cc

 // Copyright 2016 the V8 project authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
-#include <stdio.h>
+#include <limits>
 
 #include "include/libplatform/v8-tracing.h"
 #include "src/tracing/trace-event.h"
@@ -142,10 +142,10 @@ TEST(TestJSONTraceWriter) {
   std::string trace_str = stream.str();
   std::string expected_trace_str =
       "{\"traceEvents\":[{\"pid\":11,\"tid\":22,\"ts\":100,\"tts\":50,"
-      "\"ph\":\"X\",\"cat\":\"v8-cat\",\"name\":\"Test0\",\"args\":{},"
-      "\"dur\":33,\"tdur\":44},{\"pid\":55,\"tid\":66,\"ts\":110,\"tts\":55,"
-      "\"ph\":\"Y\",\"cat\":\"v8-cat\",\"name\":\"Test1\",\"args\":{},\"dur\":"
-      "77,\"tdur\":88}]}";
+      "\"ph\":\"X\",\"cat\":\"v8-cat\",\"name\":\"Test0\",\"dur\":33,"
+      "\"tdur\":44,\"args\":{}},{\"pid\":55,\"tid\":66,\"ts\":110,\"tts\":55,"
+      "\"ph\":\"Y\",\"cat\":\"v8-cat\",\"name\":\"Test1\",\"dur\":77,"
+      "\"tdur\":88,\"args\":{}}]}";
 
   CHECK_EQ(expected_trace_str, trace_str);
 
@@ -181,6 +181,134 @@ TEST(TestTracingController) {
   i::V8::SetPlatformForTesting(old_platform);
 }
 
+void GetJSONStrings(std::vector<std::string>& ret, std::string str,
+                    std::string param, std::string start_delim,
+                    std::string end_delim) {
+  size_t pos = str.find(param);
+  while (pos != std::string::npos) {
+    size_t start_pos = str.find(start_delim, pos + param.length());
+    size_t end_pos = str.find(end_delim, start_pos + 1);
+    CHECK_NE(start_pos, std::string::npos);
+    CHECK_NE(end_pos, std::string::npos);
+    ret.push_back(str.substr(start_pos + 1, end_pos - start_pos - 1));
+    pos = str.find(param, pos + 1);
+  }
+}
+
+TEST(TestTracingControllerMultipleArgsAndCopy) {
+  std::ostringstream stream;
+  v8::Platform* old_platform = i::V8::GetCurrentPlatform();
+  v8::Platform* default_platform = v8::platform::CreateDefaultPlatform();
+  i::V8::SetPlatformForTesting(default_platform);
+
+  uint64_t aa = 11;
+  unsigned int bb = 22;
+  uint16_t cc = 33;
+  unsigned char dd = 44;
+  int64_t ee = -55;
+  int ff = -66;
+  int16_t gg = -77;
+  signed char hh = -88;
+  bool ii1 = true;
+  bool ii2 = false;
+  double jj1 = 99.0;
+  double jj2 = 1e100;
+  double jj3 = std::numeric_limits<double>::quiet_NaN();
+  double jj4 = std::numeric_limits<double>::infinity();
+  double jj5 = -std::numeric_limits<double>::infinity();
+  void* kk = &aa;
+  const char* ll = "100";
+  std::string mm = "INIT";
+
+  // Create a scope for the tracing controller to terminate the trace writer.
+  {
+    TracingController tracing_controller;
+    platform::SetTracingController(default_platform, &tracing_controller);
+    TraceWriter* writer = TraceWriter::CreateJSONTraceWriter(stream);
+
+    TraceBuffer* ring_buffer =
+        TraceBuffer::CreateTraceBufferRingBuffer(1, writer);
+    tracing_controller.Initialize(ring_buffer);
+    TraceConfig* trace_config = new TraceConfig();
+    trace_config->AddIncludedCategory("v8");
+    tracing_controller.StartTracing(trace_config);
+
+    TRACE_EVENT1("v8", "v8.Test.aa", "aa", aa);
+    TRACE_EVENT1("v8", "v8.Test.bb", "bb", bb);
+    TRACE_EVENT1("v8", "v8.Test.cc", "cc", cc);
+    TRACE_EVENT1("v8", "v8.Test.dd", "dd", dd);
+    TRACE_EVENT1("v8", "v8.Test.ee", "ee", ee);
+    TRACE_EVENT1("v8", "v8.Test.ff", "ff", ff);
+    TRACE_EVENT1("v8", "v8.Test.gg", "gg", gg);
+    TRACE_EVENT1("v8", "v8.Test.hh", "hh", hh);
+    TRACE_EVENT1("v8", "v8.Test.ii", "ii1", ii1);
+    TRACE_EVENT1("v8", "v8.Test.ii", "ii2", ii2);
+    TRACE_EVENT1("v8", "v8.Test.jj1", "jj1", jj1);
+    TRACE_EVENT1("v8", "v8.Test.jj2", "jj2", jj2);
+    TRACE_EVENT1("v8", "v8.Test.jj3", "jj3", jj3);
+    TRACE_EVENT1("v8", "v8.Test.jj4", "jj4", jj4);
+    TRACE_EVENT1("v8", "v8.Test.jj5", "jj5", jj5);
+    TRACE_EVENT1("v8", "v8.Test.kk", "kk", kk);
+    TRACE_EVENT1("v8", "v8.Test.ll", "ll", ll);
+    TRACE_EVENT1("v8", "v8.Test.mm", "mm", TRACE_STR_COPY(mm.c_str()));
+
+    TRACE_EVENT2("v8", "v8.Test2.1", "aa", aa, "ll", ll);
+    TRACE_EVENT2("v8", "v8.Test2.2", "mm1", TRACE_STR_COPY(mm.c_str()), "mm2",
+                 TRACE_STR_COPY(mm.c_str()));
+
+    // Check copies are correct.
+    TRACE_EVENT_COPY_INSTANT0("v8", mm.c_str(), TRACE_EVENT_SCOPE_THREAD);
+    TRACE_EVENT_COPY_INSTANT1("v8", mm.c_str(), TRACE_EVENT_SCOPE_THREAD,
+                              mm.c_str(), mm.c_str());
+    TRACE_EVENT_COPY_INSTANT2("v8", mm.c_str(), TRACE_EVENT_SCOPE_THREAD,
+                              mm.c_str(), mm.c_str(), mm.c_str(), mm.c_str());
+    mm = "CHANGED";
+
+    tracing_controller.StopTracing();
+  }
+
+  std::string trace_str = stream.str();
+
+  std::vector<std::string> all_args, all_names, all_cats;
+  GetJSONStrings(all_args, trace_str, "\"args\"", "{", "}");
+  GetJSONStrings(all_names, trace_str, "\"name\"", "\"", "\"");
+  GetJSONStrings(all_cats, trace_str, "\"cat\"", "\"", "\"");
+
+  CHECK_EQ(all_args.size(), 23);
+  CHECK_EQ(all_args[0], "\"aa\":11");
+  CHECK_EQ(all_args[1], "\"bb\":22");
+  CHECK_EQ(all_args[2], "\"cc\":33");
+  CHECK_EQ(all_args[3], "\"dd\":44");
+  CHECK_EQ(all_args[4], "\"ee\":-55");
+  CHECK_EQ(all_args[5], "\"ff\":-66");
+  CHECK_EQ(all_args[6], "\"gg\":-77");
+  CHECK_EQ(all_args[7], "\"hh\":-88");
+  CHECK_EQ(all_args[8], "\"ii1\":true");
+  CHECK_EQ(all_args[9], "\"ii2\":false");
+  CHECK_EQ(all_args[10], "\"jj1\":99.0");
+  CHECK_EQ(all_args[11], "\"jj2\":1e+100");
+  CHECK_EQ(all_args[12], "\"jj3\":\"NaN\"");
+  CHECK_EQ(all_args[13], "\"jj4\":\"Infinity\"");
+  CHECK_EQ(all_args[14], "\"jj5\":\"-Infinity\"");
+  std::ostringstream pointer_stream;
+  pointer_stream << "\"kk\":\"" << &aa << "\"";
+  CHECK_EQ(all_args[15], pointer_stream.str());
+  CHECK_EQ(all_args[16], "\"ll\":\"100\"");
+  CHECK_EQ(all_args[17], "\"mm\":\"INIT\"");
+
+  CHECK_EQ(all_names[18], "v8.Test2.1");
+  CHECK_EQ(all_args[18], "\"aa\":11,\"ll\":\"100\"");
+  CHECK_EQ(all_args[19], "\"mm1\":\"INIT\",\"mm2\":\"INIT\"");
+
+  CHECK_EQ(all_names[20], "INIT");
+  CHECK_EQ(all_names[21], "INIT");
+  CHECK_EQ(all_args[21], "\"INIT\":\"INIT\"");
+  CHECK_EQ(all_names[22], "INIT");
+  CHECK_EQ(all_args[22], "\"INIT\":\"INIT\",\"INIT\":\"INIT\"");
+
+  i::V8::SetPlatformForTesting(old_platform);
+}
+
 }  // namespace tracing
 }  // namespace platform
 }  // namespace v8