[clangd] Add CSV export for trace metrics

Summary: Example: https://docs.google.com/spreadsheets/d/1VZKGetSUTTDe9p4ooIETmdcwUod1_aE3vgD0E9x7HhI/edit

Reviewers: kadircet

Subscribers: ilya-biryukov, MaskRay, jkorous, arphaman, jfb, usaxena95, cfe-commits

Tags: #clang

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

clang-tools-extra/clangd/support/Trace.cpp

@@ -189,6 +189,66 @@ class JSONTracer : public EventTracer {
   const llvm::sys::TimePoint<> Start;
 };
 
+// We emit CSV as specified in RFC 4180: https://www.ietf.org/rfc/rfc4180.txt.
+// \r\n line endings are used, cells with \r\n," are quoted, quotes are doubled.
+class CSVMetricTracer : public EventTracer {
+public:
+  CSVMetricTracer(llvm::raw_ostream &Out) : Out(Out) {
+    Start = std::chrono::steady_clock::now();
+
+    Out.SetUnbuffered(); // We write each line atomically.
+    Out << "Kind,Metric,Label,Value,Timestamp\r\n";
+  }
+
+  void record(const Metric &Metric, double Value,
+              llvm::StringRef Label) override {
+    assert(!needsQuote(Metric.Name));
+    std::string QuotedLabel;
+    if (needsQuote(Label))
+      Label = QuotedLabel = quote(Label);
+    uint64_t Micros = std::chrono::duration_cast<std::chrono::microseconds>(
+                          std::chrono::steady_clock::now() - Start)
+                          .count();
+    std::lock_guard<std::mutex> Lock(Mu);
+    Out << llvm::formatv("{0},{1},{2},{3:e},{4}.{5:6}\r\n",
+                         typeName(Metric.Type), Metric.Name, Label, Value,
+                         Micros / 1000000, Micros % 1000000);
+  }
+
+private:
+  llvm::StringRef typeName(Metric::MetricType T) {
+    switch (T) {
+    case Metric::Value:
+      return "v";
+    case Metric::Counter:
+      return "c";
+    case Metric::Distribution:
+      return "d";
+    }
+  }
+
+  static bool needsQuote(llvm::StringRef Text) {
+    // https://www.ietf.org/rfc/rfc4180.txt section 2.6
+    return Text.find_first_of(",\"\r\n") != llvm::StringRef::npos;
+  }
+
+  std::string quote(llvm::StringRef Text) {
+    std::string Result = "\"";
+    for (char C : Text) {
+      Result.push_back(C);
+      if (C == '"')
+        Result.push_back('"');
+    }
+    Result.push_back('"');
+    return Result;
+  }
+
+private:
+  std::mutex Mu;
+  llvm::raw_ostream &Out /*GUARDED_BY(Mu)*/;
+  std::chrono::steady_clock::time_point Start;
+};
+
 Key<std::unique_ptr<JSONTracer::JSONSpan>> JSONTracer::SpanKey;
 
 EventTracer *T = nullptr;
@@ -206,6 +266,10 @@ std::unique_ptr<EventTracer> createJSONTracer(llvm::raw_ostream &OS,
   return std::make_unique<JSONTracer>(OS, Pretty);
 }
 
+std::unique_ptr<EventTracer> createCSVMetricTracer(llvm::raw_ostream &OS) {
+  return std::make_unique<CSVMetricTracer>(OS);
+}
+
 void log(const llvm::Twine &Message) {
   if (!T)
     return;

clang-tools-extra/clangd/support/Trace.h

@@ -108,11 +108,18 @@ class Session {
 /// Create an instance of EventTracer that produces an output in the Trace Event
 /// format supported by Chrome's trace viewer (chrome://tracing).
 ///
+/// FIXME: Metrics are not recorded, some could become counter events.
+///
 /// The format is documented here:
 /// https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview
 std::unique_ptr<EventTracer> createJSONTracer(llvm::raw_ostream &OS,
                                               bool Pretty = false);
 
+/// Create an instance of EventTracer that outputs metric measurements as CSV.
+///
+/// Trace spans and instant events are ignored.
+std::unique_ptr<EventTracer> createCSVMetricTracer(llvm::raw_ostream &OS);
+
 /// Records a single instant event, associated with the current thread.
 void log(const llvm::Twine &Name);
 

clang-tools-extra/clangd/test/metrics.test

@@ -0,0 +1,11 @@
+# RUN: env CLANGD_METRICS=%t clangd -lit-test < %s && FileCheck %s < %t
+{"jsonrpc":"2.0","id":0,"method":"initialize","params":{"processId":123,"rootPath":"clangd","capabilities":{},"trace":"off"}}
+---
+{"jsonrpc":"2.0","method":"textDocument/didOpen","params":{"textDocument":{"uri":"test:///foo.c","languageId":"c","version":1,"text":"void main() {}"}}}
+# Don't verify value, timestamp, or order.
+# CHECK-DAG: d,lsp_latency,textDocument/didOpen,
+# CHECK-DAG: c,ast_access_diag,miss,
+---
+{"jsonrpc":"2.0","id":5,"method":"shutdown"}
+---
+{"jsonrpc":"2.0","method":"exit"}

clang-tools-extra/clangd/tool/ClangdMain.cpp

@@ -539,18 +539,23 @@ clangd accepts flags on the commandline, and in the CLANGD_FLAGS environment var
   // Setup tracing facilities if CLANGD_TRACE is set. In practice enabling a
   // trace flag in your editor's config is annoying, launching with
   // `CLANGD_TRACE=trace.json vim` is easier.
-  llvm::Optional<llvm::raw_fd_ostream> TraceStream;
+  llvm::Optional<llvm::raw_fd_ostream> TracerStream;
   std::unique_ptr<trace::EventTracer> Tracer;
-  if (auto *TraceFile = getenv("CLANGD_TRACE")) {
+  const char *JSONTraceFile = getenv("CLANGD_TRACE");
+  const char *MetricsCSVFile = getenv("CLANGD_METRICS");
+  const char *TracerFile = JSONTraceFile ? JSONTraceFile : MetricsCSVFile;
+  if (TracerFile) {
     std::error_code EC;
-    TraceStream.emplace(TraceFile, /*ref*/ EC,
-                        llvm::sys::fs::FA_Read | llvm::sys::fs::FA_Write);
+    TracerStream.emplace(TracerFile, /*ref*/ EC,
+                         llvm::sys::fs::FA_Read | llvm::sys::fs::FA_Write);
     if (EC) {
-      TraceStream.reset();
-      llvm::errs() << "Error while opening trace file " << TraceFile << ": "
+      TracerStream.reset();
+      llvm::errs() << "Error while opening trace file " << TracerFile << ": "
                    << EC.message();
     } else {
-      Tracer = trace::createJSONTracer(*TraceStream, PrettyPrint);
+      Tracer = (TracerFile == JSONTraceFile)
+                   ? trace::createJSONTracer(*TracerStream, PrettyPrint)
+                   : trace::createCSVMetricTracer(*TracerStream);
     }
   }
 

clang-tools-extra/clangd/unittests/support/TraceTests.cpp

@@ -11,6 +11,7 @@
 #include "support/Trace.h"
 #include "llvm/ADT/DenseMap.h"
 #include "llvm/ADT/SmallString.h"
+#include "llvm/ADT/StringExtras.h"
 #include "llvm/ADT/StringRef.h"
 #include "llvm/Support/SourceMgr.h"
 #include "llvm/Support/Threading.h"
@@ -22,7 +23,11 @@ namespace clang {
 namespace clangd {
 namespace {
 
+using testing::_;
+using testing::ElementsAre;
+using testing::MatchesRegex;
 using testing::SizeIs;
+using testing::StartsWith;
 
 MATCHER_P(StringNode, Val, "") {
   if (arg->getType() != llvm::yaml::Node::NK_Scalar) {
@@ -138,6 +143,51 @@ TEST(MetricsTracer, LatencyTest) {
   EXPECT_THAT(Tracer.takeMetric(MetricName, OpName), SizeIs(1));
 }
 
+class CSVMetricsTracerTest : public ::testing::Test {
+protected:
+  CSVMetricsTracerTest()
+      : OS(Output), Tracer(trace::createCSVMetricTracer(OS)), Session(*Tracer) {
+  }
+  trace::Metric Dist = {"dist", trace::Metric::Distribution, "lbl"};
+  trace::Metric Counter = {"cnt", trace::Metric::Counter};
+
+  std::vector<llvm::StringRef> outputLines() {
+    // Deliberately don't flush output stream, the tracer should do that.
+    // This is important when clangd crashes.
+    llvm::SmallVector<llvm::StringRef, 4> Lines;
+    llvm::StringRef(Output).split(Lines, "\r\n");
+    return {Lines.begin(), Lines.end()};
+  }
+
+  std::string Output;
+  llvm::raw_string_ostream OS;
+  std::unique_ptr<trace::EventTracer> Tracer;
+  trace::Session Session;
+};
+
+TEST_F(CSVMetricsTracerTest, RecordsValues) {
+  Dist.record(1, "x");
+  Counter.record(1, "");
+  Dist.record(2, "y");
+
+  EXPECT_THAT(
+      outputLines(),
+      ElementsAre("Kind,Metric,Label,Value,Timestamp",
+                  MatchesRegex(R"(d,dist,x,1\.000000e\+00,[0-9]+\.[0-9]{6})"),
+                  StartsWith("c,cnt,,1.000000e+00,"),
+                  StartsWith("d,dist,y,2.000000e+00,"), ""));
+}
+
+TEST_F(CSVMetricsTracerTest, Escaping) {
+  Dist.record(1, ",");
+  Dist.record(1, "a\"b");
+  Dist.record(1, "a\nb");
+
+  EXPECT_THAT(outputLines(), ElementsAre(_, StartsWith(R"(d,dist,",",1)"),
+                                         StartsWith(R"(d,dist,"a""b",1)"),
+                                         StartsWith("d,dist,\"a\nb\",1"), ""));
+}
+
 } // namespace
 } // namespace clangd
 } // namespace clang