[clang-tools-extra] 65eaec9 - [clangd] Add -log=public to redact all request info from index server logs

Sam McCall via cfe-commits cfe-commits at lists.llvm.org
Mon Nov 2 12:25:25 PST 2020


Author: Sam McCall
Date: 2020-11-02T21:25:12+01:00
New Revision: 65eaec9bd3f23f113a195edf8f2d544ec8e34b4e

URL: https://github.com/llvm/llvm-project/commit/65eaec9bd3f23f113a195edf8f2d544ec8e34b4e
DIFF: https://github.com/llvm/llvm-project/commit/65eaec9bd3f23f113a195edf8f2d544ec8e34b4e.diff

LOG: [clangd] Add -log=public to redact all request info from index server logs

The index server has access to potentially-sensitive information, e.g. a
sequence of fuzzyFind requests reveals details about code completions in the
editor which in turn reveals details about the code being edited.
This information is necessary to provide the service, and our intention[1] is it
should never be retained beyond the scope of the request (e.g. not logged).

At the same time, some log messages should be exposed:
 - server startup/index reloads etc that don't pertain to a user request
 - basic request logs (method, latency, #results, error code) for monitoring
 - errors while handling requests, without request-specific data
The -log=public design accommodates these by allowing three types of logs:
 - those not associated with any user RPC request (via context-propagation)
 - those explicitly tagged as [public] in the log line
 - logging of format strings only, with no interpolated data (error level only)

[1] Specifically: Google is likely to run public instances of this server
for LLVM and potentially other projects, they will run in this configuration.
The details agreed in a Google-internal privacy review.
As clangd developers, we'd encourage others to use this configuration for public
instances too.

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

Added: 
    

Modified: 
    clang-tools-extra/clangd/index/remote/server/Server.cpp
    clang-tools-extra/clangd/support/Logger.cpp
    clang-tools-extra/clangd/support/Logger.h
    clang-tools-extra/clangd/unittests/ClangdLSPServerTests.cpp

Removed: 
    


################################################################################
diff  --git a/clang-tools-extra/clangd/index/remote/server/Server.cpp b/clang-tools-extra/clangd/index/remote/server/Server.cpp
index 33000b1aad15..4a479eece50f 100644
--- a/clang-tools-extra/clangd/index/remote/server/Server.cpp
+++ b/clang-tools-extra/clangd/index/remote/server/Server.cpp
@@ -12,6 +12,7 @@
 #include "index/Serialization.h"
 #include "index/Symbol.h"
 #include "index/remote/marshalling/Marshalling.h"
+#include "support/Context.h"
 #include "support/Logger.h"
 #include "support/Shutdown.h"
 #include "support/ThreadsafeFS.h"
@@ -23,6 +24,7 @@
 #include "llvm/Support/CommandLine.h"
 #include "llvm/Support/Error.h"
 #include "llvm/Support/FileSystem.h"
+#include "llvm/Support/FormatVariadic.h"
 #include "llvm/Support/Path.h"
 #include "llvm/Support/Signals.h"
 #include "llvm/Support/VirtualFileSystem.h"
@@ -58,6 +60,12 @@ llvm::cl::opt<Logger::Level> LogLevel{
     llvm::cl::init(Logger::Info),
 };
 
+llvm::cl::opt<bool> LogPublic{
+    "log-public",
+    llvm::cl::desc("Avoid logging potentially-sensitive request details"),
+    llvm::cl::init(false),
+};
+
 llvm::cl::opt<std::string> TraceFile(
     "trace-file",
     llvm::cl::desc("Path to the file where tracer logs will be stored"));
@@ -72,6 +80,8 @@ llvm::cl::opt<std::string> ServerAddress(
     "server-address", llvm::cl::init("0.0.0.0:50051"),
     llvm::cl::desc("Address of the invoked server. Defaults to 0.0.0.0:50051"));
 
+static Key<grpc::ServerContext *> CurrentRequest;
+
 class RemoteIndexServer final : public v1::SymbolIndex::Service {
 public:
   RemoteIndexServer(clangd::SymbolIndex &Index, llvm::StringRef IndexRoot)
@@ -87,6 +97,7 @@ class RemoteIndexServer final : public v1::SymbolIndex::Service {
   grpc::Status Lookup(grpc::ServerContext *Context,
                       const LookupRequest *Request,
                       grpc::ServerWriter<LookupReply> *Reply) override {
+    WithContextValue(CurrentRequest, Context);
     trace::Span Tracer("LookupRequest");
     auto Req = ProtobufMarshaller->fromProtobuf(Request);
     if (!Req) {
@@ -119,6 +130,7 @@ class RemoteIndexServer final : public v1::SymbolIndex::Service {
   grpc::Status FuzzyFind(grpc::ServerContext *Context,
                          const FuzzyFindRequest *Request,
                          grpc::ServerWriter<FuzzyFindReply> *Reply) override {
+    WithContextValue(CurrentRequest, Context);
     trace::Span Tracer("FuzzyFindRequest");
     auto Req = ProtobufMarshaller->fromProtobuf(Request);
     if (!Req) {
@@ -151,6 +163,7 @@ class RemoteIndexServer final : public v1::SymbolIndex::Service {
 
   grpc::Status Refs(grpc::ServerContext *Context, const RefsRequest *Request,
                     grpc::ServerWriter<RefsReply> *Reply) override {
+    WithContextValue(CurrentRequest, Context);
     trace::Span Tracer("RefsRequest");
     auto Req = ProtobufMarshaller->fromProtobuf(Request);
     if (!Req) {
@@ -183,6 +196,7 @@ class RemoteIndexServer final : public v1::SymbolIndex::Service {
   grpc::Status Relations(grpc::ServerContext *Context,
                          const RelationsRequest *Request,
                          grpc::ServerWriter<RelationsReply> *Reply) override {
+    WithContextValue(CurrentRequest, Context);
     trace::Span Tracer("RelationsRequest");
     auto Req = ProtobufMarshaller->fromProtobuf(Request);
     if (!Req) {
@@ -229,8 +243,8 @@ void hotReload(clangd::SwapIndex &Index, llvm::StringRef IndexPath,
                       LastStatus.getLastModificationTime() &&
                   Status->getSize() == LastStatus.getSize()))
     return;
-  vlog("Found 
diff erent index version: existing index was modified at {0}, new "
-       "index was modified at {1}. Attempting to reload.",
+  vlog("Found 
diff erent index version: existing index was modified at "
+       "{0}, new index was modified at {1}. Attempting to reload.",
        LastStatus.getLastModificationTime(), Status->getLastModificationTime());
   LastStatus = *Status;
   std::unique_ptr<clang::clangd::SymbolIndex> NewIndex = loadIndex(IndexPath);
@@ -266,6 +280,29 @@ void runServerAndWait(clangd::SymbolIndex &Index, llvm::StringRef ServerAddress,
   ServerShutdownWatcher.join();
 }
 
+std::unique_ptr<Logger> makeLogger(llvm::raw_ostream &OS) {
+  if (!LogPublic)
+    return std::make_unique<StreamLogger>(OS, LogLevel);
+  // Redacted mode:
+  //  - messages outside the scope of a request: log fully
+  //  - messages tagged [public]: log fully
+  //  - errors: log the format string
+  //  - others: drop
+  class RedactedLogger : public StreamLogger {
+  public:
+    using StreamLogger::StreamLogger;
+    void log(Level L, const char *Fmt,
+             const llvm::formatv_object_base &Message) override {
+      if (Context::current().get(CurrentRequest) == nullptr ||
+          llvm::StringRef(Fmt).startswith("[public]"))
+        return StreamLogger::log(L, Fmt, Message);
+      if (L >= Error)
+        return StreamLogger::log(L, Fmt, llvm::formatv("[redacted] {0}", Fmt));
+    }
+  };
+  return std::make_unique<RedactedLogger>(OS, LogLevel);
+}
+
 } // namespace
 } // namespace remote
 } // namespace clangd
@@ -287,8 +324,8 @@ int main(int argc, char *argv[]) {
   llvm::errs().SetBuffered();
   // Don't flush stdout when logging for thread safety.
   llvm::errs().tie(nullptr);
-  clang::clangd::StreamLogger Logger(llvm::errs(), LogLevel);
-  clang::clangd::LoggingSession LoggingSession(Logger);
+  auto Logger = makeLogger(llvm::errs());
+  clang::clangd::LoggingSession LoggingSession(*Logger);
 
   llvm::Optional<llvm::raw_fd_ostream> TracerStream;
   std::unique_ptr<clang::clangd::trace::EventTracer> Tracer;

diff  --git a/clang-tools-extra/clangd/support/Logger.cpp b/clang-tools-extra/clangd/support/Logger.cpp
index 4a5d7d63bed4..e4e0499f9f57 100644
--- a/clang-tools-extra/clangd/support/Logger.cpp
+++ b/clang-tools-extra/clangd/support/Logger.cpp
@@ -28,10 +28,10 @@ LoggingSession::LoggingSession(clangd::Logger &Instance) {
 
 LoggingSession::~LoggingSession() { L = nullptr; }
 
-void detail::log(Logger::Level Level,
-                 const llvm::formatv_object_base &Message) {
+void detail::logImpl(Logger::Level Level, const char *Fmt,
+                     const llvm::formatv_object_base &Message) {
   if (L)
-    L->log(Level, Message);
+    L->log(Level, Fmt, Message);
   else {
     static std::mutex Mu;
     std::lock_guard<std::mutex> Guard(Mu);
@@ -47,7 +47,7 @@ const char *detail::debugType(const char *Filename) {
   return Filename;
 }
 
-void StreamLogger::log(Logger::Level Level,
+void StreamLogger::log(Logger::Level Level, const char *Fmt,
                        const llvm::formatv_object_base &Message) {
   if (Level < MinLevel)
     return;

diff  --git a/clang-tools-extra/clangd/support/Logger.h b/clang-tools-extra/clangd/support/Logger.h
index 0674671aa8e1..b0356cb28249 100644
--- a/clang-tools-extra/clangd/support/Logger.h
+++ b/clang-tools-extra/clangd/support/Logger.h
@@ -24,16 +24,19 @@ class Logger {
 public:
   virtual ~Logger() = default;
 
-  enum Level { Debug, Verbose, Info, Error };
+  /// The significance or severity of this message.
+  /// Typically used to filter the output to an interesting level.
+  enum Level : unsigned char { Debug, Verbose, Info, Error };
   static char indicator(Level L) { return "DVIE"[L]; }
 
   /// Implementations of this method must be thread-safe.
-  virtual void log(Level, const llvm::formatv_object_base &Message) = 0;
+  virtual void log(Level, const char *Fmt,
+                   const llvm::formatv_object_base &Message) = 0;
 };
 
 namespace detail {
 const char *debugType(const char *Filename);
-void log(Logger::Level, const llvm::formatv_object_base &);
+void logImpl(Logger::Level, const char *Fmt, const llvm::formatv_object_base &);
 
 // We often want to consume llvm::Errors by value when passing them to log().
 // We automatically wrap them in llvm::fmt_consume() as formatv requires.
@@ -43,7 +46,8 @@ inline decltype(fmt_consume(llvm::Error::success())) wrap(llvm::Error &&V) {
 }
 template <typename... Ts>
 void log(Logger::Level L, const char *Fmt, Ts &&... Vals) {
-  detail::log(L, llvm::formatv(Fmt, detail::wrap(std::forward<Ts>(Vals))...));
+  detail::logImpl(L, Fmt,
+                  llvm::formatv(Fmt, detail::wrap(std::forward<Ts>(Vals))...));
 }
 
 llvm::Error error(std::error_code, std::string &&);
@@ -119,7 +123,8 @@ class StreamLogger : public Logger {
       : MinLevel(MinLevel), Logs(Logs) {}
 
   /// Write a line to the logging stream.
-  void log(Level, const llvm::formatv_object_base &Message) override;
+  void log(Level, const char *Fmt,
+           const llvm::formatv_object_base &Message) override;
 
 private:
   Logger::Level MinLevel;

diff  --git a/clang-tools-extra/clangd/unittests/ClangdLSPServerTests.cpp b/clang-tools-extra/clangd/unittests/ClangdLSPServerTests.cpp
index 9bf45881dc47..ff3b27d8cf99 100644
--- a/clang-tools-extra/clangd/unittests/ClangdLSPServerTests.cpp
+++ b/clang-tools-extra/clangd/unittests/ClangdLSPServerTests.cpp
@@ -67,7 +67,8 @@ class LSPTest : public ::testing::Test, private clangd::Logger {
 
 private:
   // Color logs so we can distinguish them from test output.
-  void log(Level L, const llvm::formatv_object_base &Message) override {
+  void log(Level L, const char *Fmt,
+           const llvm::formatv_object_base &Message) override {
     raw_ostream::Colors Color;
     switch (L) {
     case Level::Verbose:


        


More information about the cfe-commits mailing list