From d7babe4e1247ce6144b0c7e44ea762b476503254 Mon Sep 17 00:00:00 2001
From: Sam McCall <sam.mccall@gmail.com>
Date: Wed, 24 Oct 2018 15:18:40 +0000
Subject: [PATCH] [clangd] When replying, log the method name and latency.

Summary:
This information is strictly available in the log (you can find the original
call) but it makes the log easier to follow in practice.

Reviewers: kadircet

Subscribers: ilya-biryukov, ioeric, MaskRay, jkorous, arphaman, cfe-commits

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

llvm-svn: 345150
---
 clang-tools-extra/clangd/ClangdLSPServer.cpp | 42 ++++++++++++----------------
 clang-tools-extra/clangd/ClangdLSPServer.h   |  1 -
 2 files changed, 18 insertions(+), 25 deletions(-)

diff --git a/clang-tools-extra/clangd/ClangdLSPServer.cpp b/clang-tools-extra/clangd/ClangdLSPServer.cpp
index 379fcfb..f50d3ab 100644
--- a/clang-tools-extra/clangd/ClangdLSPServer.cpp
+++ b/clang-tools-extra/clangd/ClangdLSPServer.cpp
@@ -173,6 +173,7 @@ private:
   //  - if there were multiple replies, only the first is sent
   class ReplyOnce {
     std::atomic<bool> Replied = {false};
+    std::chrono::steady_clock::time_point Start;
     json::Value ID;
     std::string Method;
     ClangdLSPServer *Server; // Null when moved-from.
@@ -181,13 +182,14 @@ private:
   public:
     ReplyOnce(const json::Value &ID, StringRef Method, ClangdLSPServer *Server,
               json::Object *TraceArgs)
-        : ID(ID), Method(Method), Server(Server), TraceArgs(TraceArgs) {
+        : Start(std::chrono::steady_clock::now()), ID(ID), Method(Method),
+          Server(Server), TraceArgs(TraceArgs) {
       assert(Server);
     }
     ReplyOnce(ReplyOnce &&Other)
-        : Replied(Other.Replied.load()), ID(std::move(Other.ID)),
-          Method(std::move(Other.Method)), Server(Other.Server),
-          TraceArgs(Other.TraceArgs) {
+        : Replied(Other.Replied.load()), Start(Other.Start),
+          ID(std::move(Other.ID)), Method(std::move(Other.Method)),
+          Server(Other.Server), TraceArgs(Other.TraceArgs) {
       Other.Server = nullptr;
     }
     ReplyOnce& operator=(ReplyOnce&&) = delete;
@@ -210,16 +212,21 @@ private:
         assert(false && "must reply to each call only once!");
         return;
       }
-      if (TraceArgs) {
-        if (Reply)
+      auto Duration = std::chrono::steady_clock::now() - Start;
+      if (Reply) {
+        log("--> reply:{0}({1}) {2:ms}", Method, ID, Duration);
+        if (TraceArgs)
           (*TraceArgs)["Reply"] = *Reply;
-        else {
-          auto Err = Reply.takeError();
+        std::lock_guard<std::mutex> Lock(Server->TranspWriter);
+        Server->Transp.reply(std::move(ID), std::move(Reply));
+      } else {
+        Error Err = Reply.takeError();
+        log("--> reply:{0}({1}) {2:ms}, error: {3}", Method, ID, Duration, Err);
+        if (TraceArgs)
           (*TraceArgs)["Error"] = to_string(Err);
-          Reply = std::move(Err);
-        }
+        std::lock_guard<std::mutex> Lock(Server->TranspWriter);
+        Server->Transp.reply(std::move(ID), std::move(Err));
       }
-      Server->reply(ID, std::move(Reply));
     }
   };
 
@@ -287,19 +294,6 @@ void ClangdLSPServer::notify(StringRef Method, json::Value Params) {
   Transp.notify(Method, std::move(Params));
 }
 
-void ClangdLSPServer::reply(json::Value ID, Expected<json::Value> Result) {
-  if (Result) {
-    log("--> reply({0})", ID);
-    std::lock_guard<std::mutex> Lock(TranspWriter);
-    Transp.reply(std::move(ID), std::move(Result));
-  } else {
-    Error Err = Result.takeError();
-    log("--> reply({0}) error: {1}", ID, Err);
-    std::lock_guard<std::mutex> Lock(TranspWriter);
-    Transp.reply(std::move(ID), std::move(Err));
-  }
-}
-
 void ClangdLSPServer::onInitialize(const InitializeParams &Params,
                                    Callback<json::Value> Reply) {
   if (Params.rootUri && *Params.rootUri)
diff --git a/clang-tools-extra/clangd/ClangdLSPServer.h b/clang-tools-extra/clangd/ClangdLSPServer.h
index f6d9ba6..70d13fc 100644
--- a/clang-tools-extra/clangd/ClangdLSPServer.h
+++ b/clang-tools-extra/clangd/ClangdLSPServer.h
@@ -153,7 +153,6 @@ private:
   std::mutex TranspWriter;
   void call(StringRef Method, llvm::json::Value Params);
   void notify(StringRef Method, llvm::json::Value Params);
-  void reply(llvm::json::Value ID, llvm::Expected<llvm::json::Value> Result);
 
   RealFileSystemProvider FSProvider;
   /// Options used for code completion
-- 
2.7.4