Author: Sam McCall Date: 2020-05-19T13:35:31+02:00 New Revision: 9b88a190b42a03753b9c49ccea34514cb40ba4ab
URL: https://github.com/llvm/llvm-project/commit/9b88a190b42a03753b9c49ccea34514cb40ba4ab DIFF: https://github.com/llvm/llvm-project/commit/9b88a190b42a03753b9c49ccea34514cb40ba4ab.diff LOG: [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 Added: clang-tools-extra/clangd/test/metrics.test Modified: clang-tools-extra/clangd/support/Trace.cpp clang-tools-extra/clangd/support/Trace.h clang-tools-extra/clangd/tool/ClangdMain.cpp clang-tools-extra/clangd/unittests/support/TraceTests.cpp Removed: ################################################################################ diff --git a/clang-tools-extra/clangd/support/Trace.cpp b/clang-tools-extra/clangd/support/Trace.cpp index 6bf4816268e5..10ae461221ee 100644 --- a/clang-tools-extra/clangd/support/Trace.cpp +++ b/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; diff --git a/clang-tools-extra/clangd/support/Trace.h b/clang-tools-extra/clangd/support/Trace.h index 90a11bb1feb4..9dc397a84b74 100644 --- a/clang-tools-extra/clangd/support/Trace.h +++ b/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); diff --git a/clang-tools-extra/clangd/test/metrics.test b/clang-tools-extra/clangd/test/metrics.test new file mode 100644 index 000000000000..874a5dad8308 --- /dev/null +++ b/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"} diff --git a/clang-tools-extra/clangd/tool/ClangdMain.cpp b/clang-tools-extra/clangd/tool/ClangdMain.cpp index 566430167a51..e59aecb2d752 100644 --- a/clang-tools-extra/clangd/tool/ClangdMain.cpp +++ b/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); } } diff --git a/clang-tools-extra/clangd/unittests/support/TraceTests.cpp b/clang-tools-extra/clangd/unittests/support/TraceTests.cpp index 10670f79be1b..cee43f73f211 100644 --- a/clang-tools-extra/clangd/unittests/support/TraceTests.cpp +++ b/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 _______________________________________________ cfe-commits mailing list cfe-commits@lists.llvm.org https://lists.llvm.org/cgi-bin/mailman/listinfo/cfe-commits
