diff --git a/clang-tools-extra/clangd/ClangdLSPServer.cpp b/clang-tools-extra/clangd/ClangdLSPServer.cpp --- a/clang-tools-extra/clangd/ClangdLSPServer.cpp +++ b/clang-tools-extra/clangd/ClangdLSPServer.cpp @@ -42,6 +42,11 @@ namespace clangd { namespace { +// Tracks end-to-end latency of high level lsp calls. Measurements are in +// seconds. +constexpr trace::Metric LSPLatency("lsp_latency", trace::Metric::Distribution, + "method_name"); + // LSP defines file versions as numbers that increase. // ClangdServer treats them as opaque and therefore uses strings instead. std::string encodeVersion(int64_t LSPVersion) { @@ -184,7 +189,7 @@ WithContext HandlerContext(handlerContext()); // Calls can be canceled by the client. Add cancellation context. WithContext WithCancel(cancelableRequestContext(ID)); - trace::Span Tracer(Method); + trace::Span Tracer(Method, LSPLatency); SPAN_ATTACH(Tracer, "Params", Params); ReplyOnce Reply(ID, Method, &Server, Tracer.Args); log("<-- {0}({1})", Method, ID); @@ -296,7 +301,7 @@ elog("Failed to decode {0} request.", Method); return; } - trace::Span Tracer(Method); + trace::Span Tracer(Method, LSPLatency); SPAN_ATTACH(Tracer, "Params", RawParams); (Server.*Handler)(P); }; @@ -1289,7 +1294,7 @@ Result.tokens = toSemanticTokens(*HT); { std::lock_guard Lock(SemanticTokensMutex); - auto& Last = LastSemanticTokens[File]; + auto &Last = LastSemanticTokens[File]; Last.tokens = Result.tokens; increment(Last.resultId); @@ -1314,7 +1319,7 @@ SemanticTokensOrEdits Result; { std::lock_guard Lock(SemanticTokensMutex); - auto& Last = LastSemanticTokens[File]; + auto &Last = LastSemanticTokens[File]; if (PrevResultID == Last.resultId) { Result.edits = diffTokens(Last.tokens, Toks); diff --git a/clang-tools-extra/clangd/ClangdServer.cpp b/clang-tools-extra/clangd/ClangdServer.cpp --- a/clang-tools-extra/clangd/ClangdServer.cpp +++ b/clang-tools-extra/clangd/ClangdServer.cpp @@ -43,6 +43,7 @@ #include "llvm/Support/Error.h" #include "llvm/Support/FileSystem.h" #include "llvm/Support/Path.h" +#include "llvm/Support/ScopedPrinter.h" #include "llvm/Support/raw_ostream.h" #include #include @@ -368,6 +369,9 @@ auto Action = [File = File.str(), NewName = NewName.str(), Pos, Opts, CB = std::move(CB), Snapshot = std::move(Snapshot), this](llvm::Expected InpAST) mutable { + // Tracks number of files edited per invocation. + static constexpr trace::Metric RenameFiles("rename_files", + trace::Metric::Distribution); if (!InpAST) return CB(InpAST.takeError()); auto GetDirtyBuffer = @@ -393,6 +397,7 @@ if (Err) return CB(std::move(Err)); } + RenameFiles.record(Edits->size()); return CB(std::move(*Edits)); }; WorkScheduler.runWithAST("Rename", File, std::move(Action)); @@ -422,6 +427,9 @@ void ClangdServer::enumerateTweaks(PathRef File, Range Sel, Callback> CB) { + // Tracks number of times a tweak has been offered. + static constexpr trace::Metric TweakAvailable( + "tweak_available", trace::Metric::Counter, "tweak_id"); auto Action = [File = File.str(), Sel, CB = std::move(CB), this](Expected InpAST) mutable { if (!InpAST) @@ -439,6 +447,7 @@ for (auto &T : prepareTweaks(*Sel, Filter)) { Res.push_back({T->id(), T->title(), T->intent()}); PreparedTweaks.insert(T->id()); + TweakAvailable.record(1, T->id()); } } @@ -451,6 +460,10 @@ void ClangdServer::applyTweak(PathRef File, Range Sel, StringRef TweakID, Callback CB) { + // Tracks number of times a tweak has been applied. + static constexpr trace::Metric TweakAttempt( + "tweak_attempt", trace::Metric::Counter, "tweak_id"); + TweakAttempt.record(1, TweakID); auto Action = [File = File.str(), Sel, TweakID = TweakID.str(), CB = std::move(CB), FS = FSProvider.getFileSystem()](Expected InpAST) mutable { diff --git a/clang-tools-extra/clangd/TUScheduler.cpp b/clang-tools-extra/clangd/TUScheduler.cpp --- a/clang-tools-extra/clangd/TUScheduler.cpp +++ b/clang-tools-extra/clangd/TUScheduler.cpp @@ -142,11 +142,19 @@ /// Returns the cached value for \p K, or llvm::None if the value is not in /// the cache anymore. If nullptr was cached for \p K, this function will /// return a null unique_ptr wrapped into an optional. - llvm::Optional> take(Key K) { + /// If \p AccessMetric is set records whether there was a hit or miss. + llvm::Optional> + take(Key K, const trace::Metric *AccessMetric = nullptr) { + // Record metric after unlocking the mutex. std::unique_lock Lock(Mut); auto Existing = findByKey(K); - if (Existing == LRU.end()) + if (Existing == LRU.end()) { + if (AccessMetric) + AccessMetric->record(1, "miss"); return None; + } + if (AccessMetric) + AccessMetric->record(1, "hit"); std::unique_ptr V = std::move(Existing->second); LRU.erase(Existing); // GCC 4.8 fails to compile `return V;`, as it tries to call the copy @@ -649,10 +657,14 @@ llvm::StringRef Name, llvm::unique_function)> Action, TUScheduler::ASTActionInvalidation Invalidation) { + // Tracks ast cache accesses for read operations. + static constexpr trace::Metric ASTAccessForRead( + "ast_access_read", trace::Metric::Counter, "result"); auto Task = [=, Action = std::move(Action)]() mutable { if (auto Reason = isCancelled()) return Action(llvm::make_error(Reason)); - llvm::Optional> AST = IdleASTs.take(this); + llvm::Optional> AST = + IdleASTs.take(this, &ASTAccessForRead); if (!AST) { StoreDiags CompilerInvocationDiagConsumer; std::unique_ptr Invocation = @@ -773,6 +785,9 @@ void ASTWorker::generateDiagnostics( std::unique_ptr Invocation, ParseInputs Inputs, std::vector CIDiags) { + // Tracks ast cache accesses for publishing diags. + static constexpr trace::Metric ASTAccessForDiag( + "ast_access_diag", trace::Metric::Counter, "result"); assert(Invocation); // No need to rebuild the AST if we won't send the diagnostics. { @@ -801,7 +816,8 @@ // We might be able to reuse the last we've built for a read request. // FIXME: It might be better to not reuse this AST. That way queued AST builds // won't be required for diags. - llvm::Optional> AST = IdleASTs.take(this); + llvm::Optional> AST = + IdleASTs.take(this, &ASTAccessForDiag); if (!AST || !InputsAreLatest) { auto RebuildStartTime = DebouncePolicy::clock::now(); llvm::Optional NewAST = ParsedAST::build( diff --git a/clang-tools-extra/clangd/support/Trace.h b/clang-tools-extra/clangd/support/Trace.h --- a/clang-tools-extra/clangd/support/Trace.h +++ b/clang-tools-extra/clangd/support/Trace.h @@ -18,15 +18,58 @@ #define LLVM_CLANG_TOOLS_EXTRA_CLANGD_SUPPORT_TRACE_H_ #include "support/Context.h" +#include "llvm/ADT/StringRef.h" #include "llvm/ADT/Twine.h" #include "llvm/Support/JSON.h" #include "llvm/Support/raw_ostream.h" +#include +#include +#include namespace clang { namespace clangd { namespace trace { -/// A consumer of trace events. The events are produced by Spans and trace::log. +/// Represents measurements of clangd events, e.g. operation latency. Those +/// measurements are recorded per-label, defaulting to an empty one for metrics +/// that don't care about it. This enables aggregation of measurements across +/// labels. For example a metric tracking accesses to a cache can have labels +/// named hit and miss. +struct Metric { + enum MetricType { + /// A number whose value is meaningful, and may vary over time. + /// Each measurement replaces the current value. + Value, + + /// An aggregate number whose rate of change over time is meaningful. + /// Each measurement is an increment for the counter. + Counter, + + /// A distribution of values with a meaningful mean and count. + /// Each measured value is a sample for the distribution. + /// The distribution is assumed not to vary, samples are aggregated over + /// time. + Distribution, + }; + constexpr Metric(llvm::StringLiteral Name, MetricType Type, + llvm::StringLiteral LabelName = "") + : Name(Name), Type(Type), LabelName(LabelName) {} + + /// Records a measurement for this metric to active tracer. + void record(double Value, llvm::StringRef Label = "") const; + + /// Uniquely identifies the metric. Should use snake_case identifiers, can use + /// dots for hierarchy if needed. e.g. method_latency, foo.bar. + const llvm::StringLiteral Name; + const MetricType Type; + /// Indicates what measurement labels represent, e.g. "operation_name" for a + /// metric tracking latencies. If non empty all measurements must also have a + /// non-empty label. + const llvm::StringLiteral LabelName; +}; + +/// A consumer of trace events and measurements. The events are produced by +/// Spans and trace::log, the measurements are produced by Metrics::record. /// Implementations of this interface must be thread-safe. class EventTracer { public: @@ -37,16 +80,20 @@ /// Usually implementations will store an object in the returned context /// whose destructor records the end of the event. /// The args are *Args, only complete when the event ends. - virtual Context beginSpan(llvm::StringRef Name, llvm::json::Object *Args) = 0; + virtual Context beginSpan(llvm::StringRef Name, llvm::json::Object *Args); // Called when a Span is destroyed (it may still be active on other threads). // beginSpan() and endSpan() will always form a proper stack on each thread. // The Context returned by beginSpan is active, but Args is not ready. // Tracers should not override this unless they need to observe strict // per-thread nesting. Instead they should observe context destruction. - virtual void endSpan(){}; + virtual void endSpan() {} /// Called for instant events. - virtual void instant(llvm::StringRef Name, llvm::json::Object &&Args) = 0; + virtual void instant(llvm::StringRef Name, llvm::json::Object &&Args) {} + + /// Called whenever a metrics records a measurement. + virtual void record(const Metric &Metric, double Value, + llvm::StringRef Label) {} }; /// Sets up a global EventTracer that consumes events produced by Span and @@ -81,6 +128,9 @@ class Span { public: Span(llvm::Twine Name); + /// Records span's duration in seconds to \p LatencyMetric with \p Name as the + /// label. + Span(llvm::Twine Name, const Metric &LatencyMetric); ~Span(); /// Mutable metadata, if this span is interested. diff --git a/clang-tools-extra/clangd/support/Trace.cpp b/clang-tools-extra/clangd/support/Trace.cpp --- a/clang-tools-extra/clangd/support/Trace.cpp +++ b/clang-tools-extra/clangd/support/Trace.cpp @@ -9,12 +9,16 @@ #include "support/Trace.h" #include "support/Context.h" #include "llvm/ADT/DenseSet.h" +#include "llvm/ADT/Optional.h" #include "llvm/ADT/ScopeExit.h" +#include "llvm/ADT/StringRef.h" #include "llvm/Support/Chrono.h" #include "llvm/Support/FormatProviders.h" #include "llvm/Support/FormatVariadic.h" #include "llvm/Support/Threading.h" #include +#include +#include #include namespace clang { @@ -209,27 +213,54 @@ } // Returned context owns Args. -static Context makeSpanContext(llvm::Twine Name, llvm::json::Object *Args) { +static Context makeSpanContext(llvm::Twine Name, llvm::json::Object *Args, + const Metric &LatencyMetric) { if (!T) return Context::current().clone(); WithContextValue WithArgs{std::unique_ptr(Args)}; + llvm::Optional WithLatency; + using Clock = std::chrono::high_resolution_clock; + WithLatency.emplace(llvm::make_scope_exit( + [StartTime = Clock::now(), Name = Name.str(), &LatencyMetric] { + LatencyMetric.record( + std::chrono::duration_cast(Clock::now() - + StartTime) + .count(), + Name); + })); return T->beginSpan(Name.isSingleStringRef() ? Name.getSingleStringRef() : llvm::StringRef(Name.str()), Args); } +// Fallback metric that measures latencies for spans without an explicit latency +// metric. Labels are span names. +constexpr Metric SpanLatency("span_latency", Metric::Distribution, "span_name"); + // Span keeps a non-owning pointer to the args, which is how users access them. // The args are owned by the context though. They stick around until the // beginSpan() context is destroyed, when the tracing engine will consume them. -Span::Span(llvm::Twine Name) +Span::Span(llvm::Twine Name) : Span(Name, SpanLatency) {} +Span::Span(llvm::Twine Name, const Metric &LatencyMetric) : Args(T ? new llvm::json::Object() : nullptr), - RestoreCtx(makeSpanContext(Name, Args)) {} + RestoreCtx(makeSpanContext(Name, Args, LatencyMetric)) {} Span::~Span() { if (T) T->endSpan(); } +void Metric::record(double Value, llvm::StringRef Label) const { + if (!T) + return; + assert((LabelName.empty() == Label.empty()) && + "recording a measurement with inconsistent labeling"); + T->record(*this, Value, Label); +} + +Context EventTracer::beginSpan(llvm::StringRef Name, llvm::json::Object *Args) { + return Context::current().clone(); +} } // namespace trace } // namespace clangd } // namespace clang diff --git a/clang-tools-extra/clangd/unittests/CMakeLists.txt b/clang-tools-extra/clangd/unittests/CMakeLists.txt --- a/clang-tools-extra/clangd/unittests/CMakeLists.txt +++ b/clang-tools-extra/clangd/unittests/CMakeLists.txt @@ -83,6 +83,7 @@ support/FunctionTests.cpp support/MarkupTests.cpp support/ThreadingTests.cpp + support/TestTracer.cpp support/TraceTests.cpp $ diff --git a/clang-tools-extra/clangd/unittests/ClangdLSPServerTests.cpp b/clang-tools-extra/clangd/unittests/ClangdLSPServerTests.cpp --- a/clang-tools-extra/clangd/unittests/ClangdLSPServerTests.cpp +++ b/clang-tools-extra/clangd/unittests/ClangdLSPServerTests.cpp @@ -14,6 +14,9 @@ #include "TestFS.h" #include "refactor/Rename.h" #include "support/Logger.h" +#include "support/TestTracer.h" +#include "llvm/ADT/StringRef.h" +#include "llvm/Support/Error.h" #include "llvm/Support/JSON.h" #include "llvm/Testing/Support/SupportHelpers.h" #include "gmock/gmock.h" @@ -147,6 +150,14 @@ DiagMessage("Use of undeclared identifier 'changed'")))); } +TEST_F(LSPTest, RecordsLatencies) { + trace::TestTracer Tracer; + auto &Client = start(); + llvm::StringLiteral MethodName = "method_name"; + EXPECT_THAT(Tracer.takeMetric("lsp_latency", MethodName), testing::SizeIs(0)); + llvm::consumeError(Client.call(MethodName, {}).take().takeError()); + EXPECT_THAT(Tracer.takeMetric("lsp_latency", MethodName), testing::SizeIs(1)); +} } // namespace } // namespace clangd } // namespace clang diff --git a/clang-tools-extra/clangd/unittests/LSPClient.cpp b/clang-tools-extra/clangd/unittests/LSPClient.cpp --- a/clang-tools-extra/clangd/unittests/LSPClient.cpp +++ b/clang-tools-extra/clangd/unittests/LSPClient.cpp @@ -20,7 +20,9 @@ ADD_FAILURE() << "No result from call after 10 seconds!"; return llvm::json::Value(nullptr); } - return std::move(*Value); + auto Res = std::move(*Value); + Value.reset(); + return Res; } llvm::json::Value LSPClient::CallResult::takeValue() { diff --git a/clang-tools-extra/clangd/unittests/RenameTests.cpp b/clang-tools-extra/clangd/unittests/RenameTests.cpp --- a/clang-tools-extra/clangd/unittests/RenameTests.cpp +++ b/clang-tools-extra/clangd/unittests/RenameTests.cpp @@ -13,6 +13,7 @@ #include "TestTU.h" #include "index/Ref.h" #include "refactor/Rename.h" +#include "support/TestTracer.h" #include "clang/Tooling/Core/Replacement.h" #include "llvm/ADT/STLExtras.h" #include "llvm/Support/MemoryBuffer.h" @@ -24,9 +25,11 @@ namespace clangd { namespace { +using testing::ElementsAre; using testing::Eq; -using testing::Pair; using testing::IsEmpty; +using testing::Pair; +using testing::SizeIs; using testing::UnorderedElementsAre; using testing::UnorderedElementsAreArray; @@ -1016,7 +1019,8 @@ }, }; - for (const auto& T : Cases) { + trace::TestTracer Tracer; + for (const auto &T : Cases) { SCOPED_TRACE(T.FooH); Annotations FooH(T.FooH); Annotations FooCC(T.FooCC); @@ -1038,8 +1042,10 @@ llvm::StringRef NewName = "NewName"; for (const auto &RenamePos : FooH.points()) { + EXPECT_THAT(Tracer.takeMetric("rename_files"), SizeIs(0)); auto FileEditsList = llvm::cantFail(runRename( Server, FooHPath, RenamePos, NewName, {/*CrossFile=*/true})); + EXPECT_THAT(Tracer.takeMetric("rename_files"), ElementsAre(2)); EXPECT_THAT( applyEdits(std::move(FileEditsList)), UnorderedElementsAre( diff --git a/clang-tools-extra/clangd/unittests/TUSchedulerTests.cpp b/clang-tools-extra/clangd/unittests/TUSchedulerTests.cpp --- a/clang-tools-extra/clangd/unittests/TUSchedulerTests.cpp +++ b/clang-tools-extra/clangd/unittests/TUSchedulerTests.cpp @@ -17,6 +17,7 @@ #include "support/Cancellation.h" #include "support/Context.h" #include "support/Path.h" +#include "support/TestTracer.h" #include "support/Threading.h" #include "clang/Basic/DiagnosticDriver.h" #include "llvm/ADT/ArrayRef.h" @@ -41,6 +42,7 @@ using ::testing::Field; using ::testing::IsEmpty; using ::testing::Pointee; +using ::testing::SizeIs; using ::testing::UnorderedElementsAre; MATCHER_P2(TUState, PreambleActivity, ASTActivity, "") { @@ -502,6 +504,7 @@ auto Opts = optsForTest(); Opts.AsyncThreadsCount = 1; Opts.RetentionPolicy.MaxRetainedASTs = 2; + trace::TestTracer Tracer; TUScheduler S(CDB, Opts); llvm::StringLiteral SourceContents = R"cpp( @@ -517,12 +520,16 @@ auto Bar = testPath("bar.cpp"); auto Baz = testPath("baz.cpp"); + EXPECT_THAT(Tracer.takeMetric("ast_access_diag", "hit"), SizeIs(0)); + EXPECT_THAT(Tracer.takeMetric("ast_access_diag", "miss"), SizeIs(0)); // Build one file in advance. We will not access it later, so it will be the // one that the cache will evict. updateWithCallback(S, Foo, SourceContents, WantDiagnostics::Yes, [&BuiltASTCounter]() { ++BuiltASTCounter; }); ASSERT_TRUE(S.blockUntilIdle(timeoutSeconds(10))); ASSERT_EQ(BuiltASTCounter.load(), 1); + EXPECT_THAT(Tracer.takeMetric("ast_access_diag", "hit"), SizeIs(0)); + EXPECT_THAT(Tracer.takeMetric("ast_access_diag", "miss"), SizeIs(1)); // Build two more files. Since we can retain only 2 ASTs, these should be // the ones we see in the cache later. @@ -532,6 +539,8 @@ [&BuiltASTCounter]() { ++BuiltASTCounter; }); ASSERT_TRUE(S.blockUntilIdle(timeoutSeconds(10))); ASSERT_EQ(BuiltASTCounter.load(), 3); + EXPECT_THAT(Tracer.takeMetric("ast_access_diag", "hit"), SizeIs(0)); + EXPECT_THAT(Tracer.takeMetric("ast_access_diag", "miss"), SizeIs(2)); // Check only the last two ASTs are retained. ASSERT_THAT(S.getFilesWithCachedAST(), UnorderedElementsAre(Bar, Baz)); @@ -541,6 +550,8 @@ [&BuiltASTCounter]() { ++BuiltASTCounter; }); ASSERT_TRUE(S.blockUntilIdle(timeoutSeconds(10))); ASSERT_EQ(BuiltASTCounter.load(), 4); + EXPECT_THAT(Tracer.takeMetric("ast_access_diag", "hit"), SizeIs(0)); + EXPECT_THAT(Tracer.takeMetric("ast_access_diag", "miss"), SizeIs(1)); // Check the AST for foo.cpp is retained now and one of the others got // evicted. @@ -758,11 +769,16 @@ EXPECT_EQ(DiagCount, 2U); } TEST_F(TUSchedulerTests, NoChangeDiags) { + trace::TestTracer Tracer; TUScheduler S(CDB, optsForTest(), captureDiags()); auto FooCpp = testPath("foo.cpp"); - auto Contents = "int a; int b;"; + const auto *Contents = "int a; int b;"; + EXPECT_THAT(Tracer.takeMetric("ast_access_read", "hit"), SizeIs(0)); + EXPECT_THAT(Tracer.takeMetric("ast_access_read", "miss"), SizeIs(0)); + EXPECT_THAT(Tracer.takeMetric("ast_access_diag", "hit"), SizeIs(0)); + EXPECT_THAT(Tracer.takeMetric("ast_access_diag", "miss"), SizeIs(0)); updateWithDiags( S, FooCpp, Contents, WantDiagnostics::No, [](std::vector) { ADD_FAILURE() << "Should not be called."; }); @@ -771,6 +787,8 @@ cantFail(std::move(IA)); }); ASSERT_TRUE(S.blockUntilIdle(timeoutSeconds(10))); + EXPECT_THAT(Tracer.takeMetric("ast_access_read", "hit"), SizeIs(0)); + EXPECT_THAT(Tracer.takeMetric("ast_access_read", "miss"), SizeIs(1)); // Even though the inputs didn't change and AST can be reused, we need to // report the diagnostics, as they were not reported previously. @@ -779,6 +797,8 @@ [&](std::vector) { SeenDiags = true; }); ASSERT_TRUE(S.blockUntilIdle(timeoutSeconds(10))); ASSERT_TRUE(SeenDiags); + EXPECT_THAT(Tracer.takeMetric("ast_access_diag", "hit"), SizeIs(1)); + EXPECT_THAT(Tracer.takeMetric("ast_access_diag", "miss"), SizeIs(0)); // Subsequent request does not get any diagnostics callback because the same // diags have previously been reported and the inputs didn't change. diff --git a/clang-tools-extra/clangd/unittests/TestTracer.h b/clang-tools-extra/clangd/unittests/TestTracer.h new file mode 100644 --- /dev/null +++ b/clang-tools-extra/clangd/unittests/TestTracer.h @@ -0,0 +1,50 @@ +//===-- TestTracer.h --------------------------------------------*- 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 +// +//===----------------------------------------------------------------------===// +// +// Allows setting up a fake tracer for tests. +// +//===----------------------------------------------------------------------===// + +#ifndef LLVM_CLANG_TOOLS_EXTRA_UNITTESTS_CLANGD_TESTFS_H +#define LLVM_CLANG_TOOLS_EXTRA_UNITTESTS_CLANGD_TESTFS_H + +#include "support/Trace.h" +#include "llvm/ADT/StringMap.h" +#include +#include +#include + +namespace clang { +namespace clangd { +namespace trace { + +/// A RAII Tracer that can be used by tests. +class TestTracer : public EventTracer { +public: + TestTracer() : Session(*this) {} + /// Stores all the measurements to be returned with take later on. + void record(const Metric &Metric, double Value, + llvm::StringRef Label) override; + + /// Returns recorded measurements for \p Metric and clears them. + std::vector take(std::string Metric, std::string Label = ""); + +private: + struct Measure { + std::string Label; + double Value; + }; + /// Measurements recorded per metric. + llvm::StringMap> Measurements; + Session Session; +}; + +} // namespace trace +} // namespace clangd +} // namespace clang +#endif diff --git a/clang-tools-extra/clangd/unittests/support/TestTracer.h b/clang-tools-extra/clangd/unittests/support/TestTracer.h new file mode 100644 --- /dev/null +++ b/clang-tools-extra/clangd/unittests/support/TestTracer.h @@ -0,0 +1,49 @@ +//===-- TestTracer.h --------------------------------------------*- 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 +// +//===----------------------------------------------------------------------===// +// +// Allows setting up a fake tracer for tests. +// +//===----------------------------------------------------------------------===// + +#ifndef LLVM_CLANG_TOOLS_EXTRA_UNITTESTS_CLANGD_SUPPORT_TESTTRACER_H +#define LLVM_CLANG_TOOLS_EXTRA_UNITTESTS_CLANGD_SUPPORT_TESTTRACER_H + +#include "support/Trace.h" +#include "llvm/ADT/StringMap.h" +#include "llvm/ADT/StringRef.h" +#include +#include +#include + +namespace clang { +namespace clangd { +namespace trace { + +/// A RAII Tracer that can be used by tests. +class TestTracer : public EventTracer { +public: + TestTracer() : Session(*this) {} + /// Stores all the measurements to be returned with take later on. + void record(const Metric &Metric, double Value, + llvm::StringRef Label) override; + + /// Returns recorded measurements for \p Metric and clears them. + std::vector takeMetric(llvm::StringRef Metric, + llvm::StringRef Label = ""); + +private: + std::mutex Mu; + /// Measurements recorded per metric per label. + llvm::StringMap>> Measurements; + Session Session; +}; + +} // namespace trace +} // namespace clangd +} // namespace clang +#endif diff --git a/clang-tools-extra/clangd/unittests/support/TestTracer.cpp b/clang-tools-extra/clangd/unittests/support/TestTracer.cpp new file mode 100644 --- /dev/null +++ b/clang-tools-extra/clangd/unittests/support/TestTracer.cpp @@ -0,0 +1,39 @@ +//===-- TestTracer.cpp - Tracing unit tests ---------------------*- 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 "TestTracer.h" +#include "support/Trace.h" +#include "llvm/ADT/StringRef.h" +#include + +namespace clang { +namespace clangd { +namespace trace { + +void TestTracer::record(const Metric &Metric, double Value, + llvm::StringRef Label) { + std::lock_guard Lock(Mu); + Measurements[Metric.Name][Label].push_back(Value); +} + +std::vector TestTracer::takeMetric(llvm::StringRef Metric, + llvm::StringRef Label) { + std::lock_guard Lock(Mu); + auto LabelsIt = Measurements.find(Metric); + if (LabelsIt == Measurements.end()) + return {}; + auto &Labels = LabelsIt->getValue(); + auto ValuesIt = Labels.find(Label); + if (ValuesIt == Labels.end()) + return {}; + auto Res = std::move(ValuesIt->getValue()); + ValuesIt->getValue().clear(); + return Res; +} +} // namespace trace +} // namespace clangd +} // namespace clang diff --git a/clang-tools-extra/clangd/unittests/support/TraceTests.cpp b/clang-tools-extra/clangd/unittests/support/TraceTests.cpp --- a/clang-tools-extra/clangd/unittests/support/TraceTests.cpp +++ b/clang-tools-extra/clangd/unittests/support/TraceTests.cpp @@ -6,10 +6,12 @@ // //===----------------------------------------------------------------------===// +#include "support/Context.h" +#include "support/TestTracer.h" #include "support/Trace.h" - #include "llvm/ADT/DenseMap.h" #include "llvm/ADT/SmallString.h" +#include "llvm/ADT/StringRef.h" #include "llvm/Support/SourceMgr.h" #include "llvm/Support/Threading.h" #include "llvm/Support/YAMLParser.h" @@ -20,6 +22,8 @@ namespace clangd { namespace { +using testing::SizeIs; + MATCHER_P(StringNode, Val, "") { if (arg->getType() != llvm::yaml::Node::NK_Scalar) { *result_listener << "is a " << arg->getVerbatimTag(); @@ -122,6 +126,18 @@ ASSERT_EQ(++Prop, Root->end()); } +TEST(MetricsTracer, LatencyTest) { + trace::TestTracer Tracer; + constexpr llvm::StringLiteral MetricName = "span_latency"; + constexpr llvm::StringLiteral OpName = "op_name"; + { + // A span should record latencies to span_latency by default. + trace::Span SpanWithLat(OpName); + EXPECT_THAT(Tracer.takeMetric(MetricName, OpName), SizeIs(0)); + } + EXPECT_THAT(Tracer.takeMetric(MetricName, OpName), SizeIs(1)); +} + } // namespace } // namespace clangd } // namespace clang