[clang-tools-extra] e64f99c - [clangd] Metric tracking through Tracer
Kadir Cetinkaya via cfe-commits
cfe-commits at lists.llvm.org
Sun May 3 01:55:25 PDT 2020
Author: Kadir Cetinkaya
Date: 2020-05-03T10:50:32+02:00
New Revision: e64f99c51a8e4476981ffdc9632b57b9fd3b5286
URL: https://github.com/llvm/llvm-project/commit/e64f99c51a8e4476981ffdc9632b57b9fd3b5286
DIFF: https://github.com/llvm/llvm-project/commit/e64f99c51a8e4476981ffdc9632b57b9fd3b5286.diff
LOG: [clangd] Metric tracking through Tracer
Summary: Introduces an endpoint to Tracer for tracking metrics on
internal events.
Reviewers: sammccall
Subscribers: ilya-biryukov, javed.absar, MaskRay, jkorous, arphaman, usaxena95, cfe-commits
Tags: #clang
Differential Revision: https://reviews.llvm.org/D78429
Added:
clang-tools-extra/clangd/unittests/TestTracer.h
clang-tools-extra/clangd/unittests/support/TestTracer.cpp
clang-tools-extra/clangd/unittests/support/TestTracer.h
Modified:
clang-tools-extra/clangd/ClangdLSPServer.cpp
clang-tools-extra/clangd/ClangdServer.cpp
clang-tools-extra/clangd/TUScheduler.cpp
clang-tools-extra/clangd/support/Trace.cpp
clang-tools-extra/clangd/support/Trace.h
clang-tools-extra/clangd/unittests/CMakeLists.txt
clang-tools-extra/clangd/unittests/ClangdLSPServerTests.cpp
clang-tools-extra/clangd/unittests/LSPClient.cpp
clang-tools-extra/clangd/unittests/RenameTests.cpp
clang-tools-extra/clangd/unittests/TUSchedulerTests.cpp
clang-tools-extra/clangd/unittests/support/TraceTests.cpp
Removed:
################################################################################
diff --git a/clang-tools-extra/clangd/ClangdLSPServer.cpp b/clang-tools-extra/clangd/ClangdLSPServer.cpp
index b0fc35bb632b..a89fa2f8104e 100644
--- a/clang-tools-extra/clangd/ClangdLSPServer.cpp
+++ b/clang-tools-extra/clangd/ClangdLSPServer.cpp
@@ -42,6 +42,11 @@ namespace clang {
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 @@ class ClangdLSPServer::MessageHandler : public Transport::MessageHandler {
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 @@ class ClangdLSPServer::MessageHandler : public Transport::MessageHandler {
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 @@ void ClangdLSPServer::onSemanticTokens(const SemanticTokensParams &Params,
Result.tokens = toSemanticTokens(*HT);
{
std::lock_guard<std::mutex> Lock(SemanticTokensMutex);
- auto& Last = LastSemanticTokens[File];
+ auto &Last = LastSemanticTokens[File];
Last.tokens = Result.tokens;
increment(Last.resultId);
@@ -1314,7 +1319,7 @@ void ClangdLSPServer::onSemanticTokensEdits(
SemanticTokensOrEdits Result;
{
std::lock_guard<std::mutex> Lock(SemanticTokensMutex);
- auto& Last = LastSemanticTokens[File];
+ auto &Last = LastSemanticTokens[File];
if (PrevResultID == Last.resultId) {
Result.edits =
diff Tokens(Last.tokens, Toks);
diff --git a/clang-tools-extra/clangd/ClangdServer.cpp b/clang-tools-extra/clangd/ClangdServer.cpp
index 8cf0d863689f..9231296e729d 100644
--- 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 <algorithm>
#include <future>
@@ -368,6 +369,9 @@ void ClangdServer::rename(PathRef File, Position Pos, llvm::StringRef NewName,
auto Action = [File = File.str(), NewName = NewName.str(), Pos, Opts,
CB = std::move(CB), Snapshot = std::move(Snapshot),
this](llvm::Expected<InputsAndAST> 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 @@ void ClangdServer::rename(PathRef File, Position Pos, llvm::StringRef NewName,
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 @@ tweakSelection(const Range &Sel, const InputsAndAST &AST) {
void ClangdServer::enumerateTweaks(PathRef File, Range Sel,
Callback<std::vector<TweakRef>> 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<InputsAndAST> InpAST) mutable {
if (!InpAST)
@@ -439,6 +447,7 @@ void ClangdServer::enumerateTweaks(PathRef File, Range Sel,
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::enumerateTweaks(PathRef File, Range Sel,
void ClangdServer::applyTweak(PathRef File, Range Sel, StringRef TweakID,
Callback<Tweak::Effect> 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<InputsAndAST> InpAST) mutable {
diff --git a/clang-tools-extra/clangd/TUScheduler.cpp b/clang-tools-extra/clangd/TUScheduler.cpp
index db5ac85ce7fc..ee6d52188934 100644
--- a/clang-tools-extra/clangd/TUScheduler.cpp
+++ b/clang-tools-extra/clangd/TUScheduler.cpp
@@ -142,11 +142,19 @@ class TUScheduler::ASTCache {
/// 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<std::unique_ptr<ParsedAST>> take(Key K) {
+ /// If \p AccessMetric is set records whether there was a hit or miss.
+ llvm::Optional<std::unique_ptr<ParsedAST>>
+ take(Key K, const trace::Metric *AccessMetric = nullptr) {
+ // Record metric after unlocking the mutex.
std::unique_lock<std::mutex> 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<ParsedAST> 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 @@ void ASTWorker::runWithAST(
llvm::StringRef Name,
llvm::unique_function<void(llvm::Expected<InputsAndAST>)> 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<CancelledError>(Reason));
- llvm::Optional<std::unique_ptr<ParsedAST>> AST = IdleASTs.take(this);
+ llvm::Optional<std::unique_ptr<ParsedAST>> AST =
+ IdleASTs.take(this, &ASTAccessForRead);
if (!AST) {
StoreDiags CompilerInvocationDiagConsumer;
std::unique_ptr<CompilerInvocation> Invocation =
@@ -773,6 +785,9 @@ void ASTWorker::updatePreamble(std::unique_ptr<CompilerInvocation> CI,
void ASTWorker::generateDiagnostics(
std::unique_ptr<CompilerInvocation> Invocation, ParseInputs Inputs,
std::vector<Diag> 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 @@ void ASTWorker::generateDiagnostics(
// 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<std::unique_ptr<ParsedAST>> AST = IdleASTs.take(this);
+ llvm::Optional<std::unique_ptr<ParsedAST>> AST =
+ IdleASTs.take(this, &ASTAccessForDiag);
if (!AST || !InputsAreLatest) {
auto RebuildStartTime = DebouncePolicy::clock::now();
llvm::Optional<ParsedAST> NewAST = ParsedAST::build(
diff --git a/clang-tools-extra/clangd/support/Trace.cpp b/clang-tools-extra/clangd/support/Trace.cpp
index b880a5b3411d..6bf4816268e5 100644
--- 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 <atomic>
+#include <chrono>
+#include <memory>
#include <mutex>
namespace clang {
@@ -209,27 +213,54 @@ void log(const llvm::Twine &Message) {
}
// 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<llvm::json::Object>(Args)};
+ llvm::Optional<WithContextValue> 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<std::chrono::milliseconds>(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/support/Trace.h b/clang-tools-extra/clangd/support/Trace.h
index e2c91eb4f100..c027595b85ed 100644
--- 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 <chrono>
+#include <string>
+#include <vector>
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 @@ class EventTracer {
/// 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 @@ void log(const llvm::Twine &Name);
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/unittests/CMakeLists.txt b/clang-tools-extra/clangd/unittests/CMakeLists.txt
index 017d7fbeb8e7..cccb3ce7308a 100644
--- a/clang-tools-extra/clangd/unittests/CMakeLists.txt
+++ b/clang-tools-extra/clangd/unittests/CMakeLists.txt
@@ -83,6 +83,7 @@ add_unittest(ClangdUnitTests ClangdTests
support/FunctionTests.cpp
support/MarkupTests.cpp
support/ThreadingTests.cpp
+ support/TestTracer.cpp
support/TraceTests.cpp
$<TARGET_OBJECTS:obj.clangDaemonTweaks>
diff --git a/clang-tools-extra/clangd/unittests/ClangdLSPServerTests.cpp b/clang-tools-extra/clangd/unittests/ClangdLSPServerTests.cpp
index aa65a2eb521d..6016003e90d5 100644
--- 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 @@ TEST_F(LSPTest, DiagnosticsHeaderSaved) {
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
index 08bbba2c3e41..d2931cb9c24f 100644
--- a/clang-tools-extra/clangd/unittests/LSPClient.cpp
+++ b/clang-tools-extra/clangd/unittests/LSPClient.cpp
@@ -20,7 +20,9 @@ llvm::Expected<llvm::json::Value> clang::clangd::LSPClient::CallResult::take() {
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
index eaf74cf062af..2d2835a12ff7 100644
--- 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 clang {
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 @@ TEST(CrossFileRenameTests, WithUpToDateIndex) {
},
};
- 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 @@ TEST(CrossFileRenameTests, WithUpToDateIndex) {
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
index 1ed73ed46e22..9e6ad6c9b6e1 100644
--- 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::Eq;
using ::testing::Field;
using ::testing::IsEmpty;
using ::testing::Pointee;
+using ::testing::SizeIs;
using ::testing::UnorderedElementsAre;
MATCHER_P2(TUState, PreambleActivity, ASTActivity, "") {
@@ -502,6 +504,7 @@ TEST_F(TUSchedulerTests, EvictedAST) {
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 @@ TEST_F(TUSchedulerTests, EvictedAST) {
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 @@ TEST_F(TUSchedulerTests, EvictedAST) {
[&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 @@ TEST_F(TUSchedulerTests, EvictedAST) {
[&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 @@ TEST_F(TUSchedulerTests, ForceRebuild) {
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<Diag>) { ADD_FAILURE() << "Should not be called."; });
@@ -771,6 +787,8 @@ TEST_F(TUSchedulerTests, NoChangeDiags) {
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 @@ TEST_F(TUSchedulerTests, NoChangeDiags) {
[&](std::vector<Diag>) { 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
index 000000000000..ebe547355524
--- /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 <string>
+#include <utility>
+#include <vector>
+
+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<double> take(std::string Metric, std::string Label = "");
+
+private:
+ struct Measure {
+ std::string Label;
+ double Value;
+ };
+ /// Measurements recorded per metric.
+ llvm::StringMap<std::vector<Measure>> 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
index 000000000000..2a45f09f3bf1
--- /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 <mutex>
+
+namespace clang {
+namespace clangd {
+namespace trace {
+
+void TestTracer::record(const Metric &Metric, double Value,
+ llvm::StringRef Label) {
+ std::lock_guard<std::mutex> Lock(Mu);
+ Measurements[Metric.Name][Label].push_back(Value);
+}
+
+std::vector<double> TestTracer::takeMetric(llvm::StringRef Metric,
+ llvm::StringRef Label) {
+ std::lock_guard<std::mutex> 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/TestTracer.h b/clang-tools-extra/clangd/unittests/support/TestTracer.h
new file mode 100644
index 000000000000..6d59fa536aa0
--- /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 <mutex>
+#include <string>
+#include <vector>
+
+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<double> takeMetric(llvm::StringRef Metric,
+ llvm::StringRef Label = "");
+
+private:
+ std::mutex Mu;
+ /// Measurements recorded per metric per label.
+ llvm::StringMap<llvm::StringMap<std::vector<double>>> Measurements;
+ Session Session;
+};
+
+} // namespace trace
+} // namespace clangd
+} // namespace clang
+#endif
diff --git a/clang-tools-extra/clangd/unittests/support/TraceTests.cpp b/clang-tools-extra/clangd/unittests/support/TraceTests.cpp
index 1599df55fb91..0be16e63b963 100644
--- 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 clang {
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 @@ TEST(TraceTest, SmokeTest) {
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
More information about the cfe-commits
mailing list