Performance tracing facility for clangd.

Summary:
This lets you visualize clangd's activity on different threads over time,
and understand critical paths of requests and object lifetimes.
The data produced can be visualized in Chrome (at chrome://tracing), or
in a standalone copy of catapult (http://github.com/catapult-project/catapult)

This patch consists of:
 - a command line flag "-trace" that causes clangd to emit JSON trace data
 - an API (in Trace.h) allowing clangd code to easily add events to the stream
 - several initial uses of this API to capture JSON-RPC requests, builds, logs

Example result: https://photos.app.goo.gl/12L9swaz5REGQ1rm1

Caveats:
 - JSON serialization is ad-hoc (isn't it everywhere?) so the API is
   limited to naming events rather than attaching arbitrary metadata.
   I'd like to fix this (I think we could use a JSON-object abstraction).
 - The recording is very naive: events are written immediately by
   locking a mutex. Contention on the mutex might disturb performance.
 - For now it just traces instants or spans on the current thread.
   There are other things that make sense to show (cross-thread flows,
   non-thread resources such as ASTs). But we have to start somewhere.

Reviewers: ioeric, ilya-biryukov

Subscribers: cfe-commits, mgorny

Differential Revision: https://reviews.llvm.org/D39086

2 files changed, 121 insertions, 0 deletions

diff --git a/clang-tools-extra/unittests/clangd/CMakeLists.txt b/clang-tools-extra/unittests/clangd/CMakeLists.txt
index 38ae2803fd2..f45bc712381 100644
--- a/clang-tools-extra/unittests/clangd/CMakeLists.txt
+++ b/clang-tools-extra/unittests/clangd/CMakeLists.txt
@@ -10,6 +10,7 @@ include_directories(
 
 add_extra_unittest(ClangdTests
   ClangdTests.cpp
+  TraceTests.cpp
   )
 
 target_link_libraries(ClangdTests
diff --git a/clang-tools-extra/unittests/clangd/TraceTests.cpp b/clang-tools-extra/unittests/clangd/TraceTests.cpp
new file mode 100644
index 00000000000..a858536a450
--- /dev/null
+++ b/clang-tools-extra/unittests/clangd/TraceTests.cpp
@@ -0,0 +1,120 @@
+//===-- TraceTests.cpp - Tracing unit tests ---------------------*- C++ -*-===//
+//
+//                     The LLVM Compiler Infrastructure
+//
+// This file is distributed under the University of Illinois Open Source
+// License. See LICENSE.TXT for details.
+//
+//===----------------------------------------------------------------------===//
+
+#include "Trace.h"
+
+#include "llvm/ADT/DenseMap.h"
+#include "llvm/ADT/SmallString.h"
+#include "llvm/Support/SourceMgr.h"
+#include "llvm/Support/YAMLParser.h"
+#include "gmock/gmock.h"
+#include "gtest/gtest.h"
+
+namespace clang {
+namespace clangd {
+namespace {
+using namespace llvm;
+
+MATCHER_P(StringNode, Val, "") {
+  if (arg->getType() != yaml::Node::NK_Scalar) {
+    *result_listener << "is a " << arg->getVerbatimTag();
+    return false;
+  }
+  SmallString<32> S;
+  return Val == static_cast<yaml::ScalarNode *>(arg)->getValue(S);
+}
+
+// Checks that N is a Mapping (JS object) with the expected scalar properties.
+// The object must have all the Expected properties, but may have others.
+bool VerifyObject(yaml::Node &N, std::map<std::string, std::string> Expected) {
+  auto *M = dyn_cast<yaml::MappingNode>(&N);
+  if (!M) {
+    ADD_FAILURE() << "Not an object";
+    return false;
+  }
+  bool Match = true;
+  SmallString<32> Tmp;
+  for (auto Prop : *M) {
+    auto *K = dyn_cast_or_null<yaml::ScalarNode>(Prop.getKey());
+    if (!K)
+      continue;
+    std::string KS = K->getValue(Tmp).str();
+    auto I = Expected.find(KS);
+    if (I == Expected.end())
+      continue; // Ignore properties with no assertion.
+
+    auto *V = dyn_cast_or_null<yaml::ScalarNode>(Prop.getValue());
+    if (!V) {
+      ADD_FAILURE() << KS << " is not a string";
+      Match = false;
+    }
+    std::string VS = V->getValue(Tmp).str();
+    if (VS != I->second) {
+      ADD_FAILURE() << KS << " expected " << I->second << " but actual " << VS;
+      Match = false;
+    }
+    Expected.erase(I);
+  }
+  for (const auto &P : Expected) {
+    ADD_FAILURE() << P.first << " missing, expected " << P.second;
+    Match = false;
+  }
+  return Match;
+}
+
+TEST(TraceTest, SmokeTest) {
+  // Capture some events.
+  std::string JSON;
+  {
+    raw_string_ostream OS(JSON);
+    auto Session = trace::Session::create(OS);
+    {
+      trace::Span S("A");
+      trace::log("B");
+    }
+  }
+
+  // Get the root JSON object using the YAML parser.
+  SourceMgr SM;
+  yaml::Stream Stream(JSON, SM);
+  auto Doc = Stream.begin();
+  ASSERT_NE(Doc, Stream.end());
+  auto *Root = dyn_cast_or_null<yaml::MappingNode>(Doc->getRoot());
+  ASSERT_NE(Root, nullptr) << "Root should be an object";
+
+  // We expect in order:
+  //   displayTimeUnit: "ns"
+  //   traceEvents: [process name, thread name, start span, log, end span]
+  // (The order doesn't matter, but the YAML parser is awkward to use otherwise)
+  auto Prop = Root->begin();
+  ASSERT_NE(Prop, Root->end()) << "Expected displayTimeUnit property";
+  ASSERT_THAT(Prop->getKey(), StringNode("displayTimeUnit"));
+  EXPECT_THAT(Prop->getValue(), StringNode("ns"));
+  ASSERT_NE(++Prop, Root->end()) << "Expected traceEvents property";
+  EXPECT_THAT(Prop->getKey(), StringNode("traceEvents"));
+  auto *Events = dyn_cast_or_null<yaml::SequenceNode>(Prop->getValue());
+  ASSERT_NE(Events, nullptr) << "traceEvents should be an array";
+  auto Event = Events->begin();
+  ASSERT_NE(Event, Events->end()) << "Expected process name";
+  EXPECT_TRUE(VerifyObject(*Event, {{"ph", "M"}, {"name", "process_name"}}));
+  ASSERT_NE(++Event, Events->end()) << "Expected thread name";
+  EXPECT_TRUE(VerifyObject(*Event, {{"ph", "M"}, {"name", "thread_name"}}));
+  ASSERT_NE(++Event, Events->end()) << "Expected span start";
+  EXPECT_TRUE(VerifyObject(*Event, {{"ph", "B"}, {"name", "A"}}));
+  ASSERT_NE(++Event, Events->end()) << "Expected log message";
+  EXPECT_TRUE(VerifyObject(*Event, {{"ph", "i"}, {"name", "B"}}));
+  ASSERT_NE(++Event, Events->end()) << "Expected span end";
+  EXPECT_TRUE(VerifyObject(*Event, {{"ph", "E"}}));
+  ASSERT_EQ(++Event, Events->end());
+  ASSERT_EQ(++Prop, Root->end());
+}
+
+} // namespace
+} // namespace clangd
+} // namespace clang