[clangd] Add more logs and attach tracers to remote index server routines

[kbobyrev]

Rebase on top of parent revision, add more logging on the client side.

[sammccall]

Server-side tracing looks nice, but you'll need some flags to allow actually extracting a trace, right?

clang-tools-extra/clangd/index/remote/server/Server.cpp

62

Nit: this is "LookupRequest" on the client side. I'd suggest just the same on the server, or "Recv.LookupRequest" or so? to make it easier to correspond them

63

you don't do this on the client side, but could

63

prefer DebugString over ShortDebugString, the missing newlines can make it hard to follow

98

you don't do this on the client side, but should

[kbobyrev]

Resolve the comments.

[kbobyrev]

clang-tools-extra/clangd/index/remote/server/Server.cpp

63

Do you mean logging RPCRequest there? Done now.

[kbobyrev]

Rebase on top of master

[kbobyrev]

In favor of D84499 with clean diffs.

[kbobyrev]

Reset D83831 to master.

clang-tools-extra/clangd/index/remote/Client.cpp

 //===--- Client.cpp ----------------------------------------------*- C++-*-===//
 //
 // Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
 // See https://llvm.org/LICENSE.txt for license information.
 // SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
 //
 //===----------------------------------------------------------------------===//
 
 #include <grpc++/grpc++.h>
 
 #include "Client.h"
 #include "Index.grpc.pb.h"
 #include "index/Index.h"
 #include "index/Serialization.h"
 #include "marshalling/Marshalling.h"
 #include "support/Logger.h"
 #include "support/Trace.h"
bool streamRPC(ClangdRequestT Request,
     grpc::ClientContext Context;
     std::chrono::system_clock::time_point Deadline =
         std::chrono::system_clock::now() + DeadlineWaitingTime;
     Context.set_deadline(Deadline);
     auto Reader = (Stub.get()->*RPCCall)(&Context, RPCRequest);
     llvm::BumpPtrAllocator Arena;
     llvm::UniqueStringSaver Strings(Arena);
     ReplyT Reply;
+    unsigned Received = 0;
+    unsigned FailedToParse = 0;
     while (Reader->Read(&Reply)) {
       if (!Reply.has_stream_result()) {
         FinalResult = Reply.final_result();
         continue;
       }
       auto Response =
           fromProtobuf(Reply.stream_result(), &Strings, ProjectRoot);
       if (!Response) {
         elog("Received invalid {0}", ReplyT::descriptor()->name());
+        ++FailedToParse;
         continue;
       }
       Callback(*Response);
+      ++Received;
     }
-    SPAN_ATTACH(Tracer, "status", Reader->Finish().ok());
+    SPAN_ATTACH(Tracer, "Status", Reader->Finish().ok());
+    SPAN_ATTACH(Tracer, "Received", Received);
+    SPAN_ATTACH(Tracer, "Failed to parse", FailedToParse);
     return FinalResult;
   }
 
 public:
   IndexClient(
       std::shared_ptr<grpc::Channel> Channel, llvm::StringRef ProjectRoot,
       std::chrono::milliseconds DeadlineTime = std::chrono::milliseconds(1000))
       : Stub(remote::SymbolIndex::NewStub(Channel)), ProjectRoot(ProjectRoot),

clang-tools-extra/clangd/index/remote/server/Server.cpp

 //===--- Server.cpp - gRPC-based Remote Index Server  ---------------------===//
 //
 // Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
 // See https://llvm.org/LICENSE.txt for license information.
 // SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
 //
 //===----------------------------------------------------------------------===//
 
 #include "index/Index.h"
 #include "index/Serialization.h"
 #include "index/remote/marshalling/Marshalling.h"
+#include "support/Logger.h"
+#include "support/Trace.h"
 #include "llvm/ADT/StringRef.h"
 #include "llvm/Support/CommandLine.h"
 #include "llvm/Support/Path.h"
 #include "llvm/Support/Signals.h"
 
 #include <grpc++/grpc++.h>
 #include <grpc++/health_check_service_interface.h>
 
RemoteIndexServer(std::unique_ptr<clangd::SymbolIndex> Index,
     llvm::sys::path::native(NativePath);
     IndexedProjectRoot = std::string(NativePath);
   }
 
 private:
   grpc::Status Lookup(grpc::ServerContext *Context,
                       const LookupRequest *Request,
                       grpc::ServerWriter<LookupReply> *Reply) override {
+    trace::Span Tracer("Remote index server Lookup");
+    SPAN_ATTACH(Tracer, "LookupRequest", Request->ShortDebugString());
     clangd::LookupRequest Req;
     for (const auto &ID : Request->ids()) {
       auto SID = SymbolID::fromStr(StringRef(ID));
-      if (!SID)
+      if (!SID) {
+        elog("Lookup request cancelled: invalid SymbolID {1}", SID.takeError());
         return grpc::Status::CANCELLED;
+      }
       Req.IDs.insert(*SID);
     }
+    unsigned Sent = 0;
+    unsigned FailedToSend = 0;
     Index->lookup(Req, [&](const clangd::Symbol &Sym) {
       auto SerializedSymbol = toProtobuf(Sym, IndexedProjectRoot);
-      if (!SerializedSymbol)
+      if (!SerializedSymbol) {
+        ++FailedToSend;
         return;
+      }
       LookupReply NextMessage;
       *NextMessage.mutable_stream_result() = *SerializedSymbol;
       Reply->Write(NextMessage);
+      ++Sent;
     });
+    SPAN_ATTACH(Tracer, "Sent", Sent);
+    SPAN_ATTACH(Tracer, "Failed to send", FailedToSend);
     LookupReply LastMessage;
     LastMessage.set_final_result(true);
     Reply->Write(LastMessage);
     return grpc::Status::OK;
   }
 
   grpc::Status FuzzyFind(grpc::ServerContext *Context,
                          const FuzzyFindRequest *Request,
                          grpc::ServerWriter<FuzzyFindReply> *Reply) override {
+    trace::Span Tracer("Remote index server FuzzyFind");
+    SPAN_ATTACH(Tracer, "FuzzyFindRequest", Request->ShortDebugString());
     const auto Req = fromProtobuf(Request, IndexedProjectRoot);
+    unsigned Sent = 0;
+    unsigned FailedToSend = 0;
     bool HasMore = Index->fuzzyFind(Req, [&](const clangd::Symbol &Sym) {
       auto SerializedSymbol = toProtobuf(Sym, IndexedProjectRoot);
-      if (!SerializedSymbol)
+      if (!SerializedSymbol) {
+        ++FailedToSend;
         return;
+      }
       FuzzyFindReply NextMessage;
       *NextMessage.mutable_stream_result() = *SerializedSymbol;
       Reply->Write(NextMessage);
+      ++Sent;
     });
+    SPAN_ATTACH(Tracer, "Sent", Sent);
+    SPAN_ATTACH(Tracer, "Failed to send", FailedToSend);
     FuzzyFindReply LastMessage;
     LastMessage.set_final_result(HasMore);
     Reply->Write(LastMessage);
     return grpc::Status::OK;
   }
 
   grpc::Status Refs(grpc::ServerContext *Context, const RefsRequest *Request,
                     grpc::ServerWriter<RefsReply> *Reply) override {
+    trace::Span Tracer("Remote index server Refs");
+    SPAN_ATTACH(Tracer, "RefsRequest", Request->ShortDebugString());
     clangd::RefsRequest Req;
     for (const auto &ID : Request->ids()) {
       auto SID = SymbolID::fromStr(StringRef(ID));
-      if (!SID)
+      if (!SID) {
+        elog("Refs request cancelled: invalid SymbolID {1}", SID.takeError());
         return grpc::Status::CANCELLED;
+      }
       Req.IDs.insert(*SID);
     }
+    unsigned Sent = 0;
+    unsigned FailedToSend = 0;
     bool HasMore = Index->refs(Req, [&](const clangd::Ref &Reference) {
       auto SerializedRef = toProtobuf(Reference, IndexedProjectRoot);
-      if (!SerializedRef)
+      if (!SerializedRef) {
+        ++FailedToSend;
         return;
+      }
       RefsReply NextMessage;
       *NextMessage.mutable_stream_result() = *SerializedRef;
       Reply->Write(NextMessage);
+      ++Sent;
     });
+    SPAN_ATTACH(Tracer, "Sent", Sent);
+    SPAN_ATTACH(Tracer, "Failed to send", FailedToSend);
     RefsReply LastMessage;
     LastMessage.set_final_result(HasMore);
     Reply->Write(LastMessage);
     return grpc::Status::OK;
   }
 
   std::unique_ptr<clangd::SymbolIndex> Index;
   std::string IndexedProjectRoot;