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

llvm-svn: 317193

1 files changed, 23 insertions, 13 deletions

diff --git a/clang-tools-extra/clangd/JSONRPCDispatcher.cpp b/clang-tools-extra/clangd/JSONRPCDispatcher.cpp
index 0aa1f396a9e..121ddb9bc8f 100644
--- a/clang-tools-extra/clangd/JSONRPCDispatcher.cpp
+++ b/clang-tools-extra/clangd/JSONRPCDispatcher.cpp
@@ -9,6 +9,7 @@
 
 #include "JSONRPCDispatcher.h"
 #include "ProtocolHandlers.h"
+#include "Trace.h"
 #include "llvm/ADT/SmallString.h"
 #include "llvm/Support/SourceMgr.h"
 #include "llvm/Support/YAMLParser.h"
@@ -32,6 +33,7 @@ void JSONOutput::writeMessage(const Twine &Message) {
 }
 
 void JSONOutput::log(const Twine &Message) {
+  trace::log(Message);
   std::lock_guard<std::mutex> Guard(StreamMutex);
   Logs << Message;
   Logs.flush();
@@ -75,8 +77,10 @@ callHandler(const llvm::StringMap<JSONRPCDispatcher::Handler> &Handlers,
             llvm::yaml::MappingNode *Params,
             const JSONRPCDispatcher::Handler &UnknownHandler, JSONOutput &Out) {
   llvm::SmallString<64> MethodStorage;
-  auto I = Handlers.find(Method->getValue(MethodStorage));
+  llvm::StringRef MethodStr = Method->getValue(MethodStorage);
+  auto I = Handlers.find(MethodStr);
   auto &Handler = I != Handlers.end() ? I->second : UnknownHandler;
+  trace::Span Tracer(MethodStr);
   Handler(RequestContext(Out, Id ? Id->getRawValue() : ""), Params);
 }
 
@@ -206,21 +210,27 @@ void clangd::runLanguageServerLoop(std::istream &In, JSONOutput &Out,
     }
 
     if (ContentLength > 0) {
-      // Now read the JSON. Insert a trailing null byte as required by the YAML
-      // parser.
       std::vector<char> JSON(ContentLength + 1, '\0');
-      In.read(JSON.data(), ContentLength);
-      Out.mirrorInput(StringRef(JSON.data(), In.gcount()));
-
-      // If the stream is aborted before we read ContentLength bytes, In
-      // will have eofbit and failbit set.
-      if (!In) {
-        Out.log("Input was aborted. Read only " + std::to_string(In.gcount()) +
-                " bytes of expected " + std::to_string(ContentLength) + ".\n");
-        break;
+      llvm::StringRef JSONRef;
+      {
+        trace::Span Tracer("Reading request");
+        // Now read the JSON. Insert a trailing null byte as required by the
+        // YAML parser.
+        In.read(JSON.data(), ContentLength);
+        Out.mirrorInput(StringRef(JSON.data(), In.gcount()));
+
+        // If the stream is aborted before we read ContentLength bytes, In
+        // will have eofbit and failbit set.
+        if (!In) {
+          Out.log("Input was aborted. Read only " +
+                  std::to_string(In.gcount()) + " bytes of expected " +
+                  std::to_string(ContentLength) + ".\n");
+          break;
+        }
+
+        JSONRef = StringRef(JSON.data(), ContentLength);
       }
 
-      llvm::StringRef JSONRef(JSON.data(), ContentLength);
       // Log the message.
       Out.log("<-- " + JSONRef + "\n");