kadircet updated this revision to Diff 261156.
kadircet marked an inline comment as done.
kadircet added a comment.
- Separate concept of a metric and measurement
- Tie latency tracking to trace::Spans.
Repository:
rG LLVM Github Monorepo
CHANGES SINCE LAST ACTION
https://reviews.llvm.org/D78429/new/
https://reviews.llvm.org/D78429
Files:
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/support/TraceTests.cpp
Index: clang-tools-extra/clangd/unittests/support/TraceTests.cpp
===================================================================
--- clang-tools-extra/clangd/unittests/support/TraceTests.cpp
+++ clang-tools-extra/clangd/unittests/support/TraceTests.cpp
@@ -6,10 +6,11 @@
//
//===----------------------------------------------------------------------===//
+#include "support/Context.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"
@@ -122,6 +123,50 @@
ASSERT_EQ(++Prop, Root->end());
}
+class MetricsTracerTest : public ::testing::Test {
+public:
+ MetricsTracerTest() : Tracer(Metrics), Session(Tracer) {}
+
+protected:
+ class MetricsTracer : public trace::EventTracer {
+ public:
+ MetricsTracer(std::vector<llvm::StringLiteral> &Metrics)
+ : Metrics(Metrics) {}
+ Context beginSpan(llvm::StringRef, llvm::json::Object *) override {
+ return Context::current().clone();
+ }
+ void record(const trace::Metric &Metric, double Value,
+ llvm::StringRef Label = "") override {
+ Metrics.push_back(Metric.Name);
+ }
+ void instant(llvm::StringRef, llvm::json::Object &&) override {}
+
+ private:
+ std::vector<llvm::StringLiteral> &Metrics;
+ };
+ std::vector<llvm::StringLiteral> Metrics;
+ MetricsTracer Tracer;
+ trace::Session Session;
+};
+
+TEST_F(MetricsTracerTest, RecordTest) {
+ constexpr llvm::StringLiteral MetricName = "metric";
+ constexpr trace::Metric M(MetricName, trace::Metric::Counter);
+ EXPECT_THAT(Metrics, testing::IsEmpty());
+ M.record(1);
+ EXPECT_THAT(Metrics, testing::ElementsAre(MetricName));
+}
+
+TEST_F(MetricsTracerTest, LatencyTest) {
+ constexpr llvm::StringLiteral MetricName = "latencies";
+ constexpr trace::Metric LatMetric(MetricName, trace::Metric::Distribution);
+ {
+ trace::Span SpanWithLat("op_name", &LatMetric);
+ EXPECT_THAT(Metrics, testing::IsEmpty());
+ }
+ EXPECT_THAT(Metrics, testing::ElementsAre(MetricName));
+}
+
} // namespace
} // namespace clangd
} // namespace clang
Index: clang-tools-extra/clangd/support/Trace.h
===================================================================
--- clang-tools-extra/clangd/support/Trace.h
+++ clang-tools-extra/clangd/support/Trace.h
@@ -18,14 +18,47 @@
#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 {
+/// Represents measurements of clangd events, e.g. operation latency.
+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)
+ : Name(Name), Type(Type) {}
+
+ /// 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
+ /// slashes for hierarchy if needed. e.g. method_latency, foo.bar.
+ const llvm::StringLiteral Name;
+ const MetricType Type;
+};
+
/// A consumer of trace events. The events are produced by Spans and trace::log.
/// Implementations of this interface must be thread-safe.
class EventTracer {
@@ -47,6 +80,10 @@
/// Called for instant events.
virtual void instant(llvm::StringRef Name, llvm::json::Object &&Args) = 0;
+
+ /// Called whenever an event exports 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
@@ -80,7 +117,9 @@
/// SomeJSONExpr is evaluated and copied only if actually needed.
class Span {
public:
- Span(llvm::Twine Name);
+ /// If \p LatencyMetric is non-null, it will receive a measurement reflecting
+ /// the spans lifetime. Label of measurement will be \p Name.
+ Span(llvm::Twine Name, const Metric *LatencyMetric = nullptr);
~Span();
/// Mutable metadata, if this span is interested.
Index: clang-tools-extra/clangd/support/Trace.cpp
===================================================================
--- clang-tools-extra/clangd/support/Trace.cpp
+++ 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,10 +213,23 @@
}
// 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;
+ if (LatencyMetric) {
+ 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);
@@ -221,15 +238,21 @@
// 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, 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;
+ T->record(*this, Value, Label);
+}
+
} // namespace trace
} // namespace clangd
} // namespace clang
Index: clang-tools-extra/clangd/TUScheduler.cpp
===================================================================
--- clang-tools-extra/clangd/TUScheduler.cpp
+++ clang-tools-extra/clangd/TUScheduler.cpp
@@ -102,6 +102,9 @@
return None;
}
+// Used to track ast cache utilization.
+constexpr static trace::Metric ASTCacheAccess("ast_cache_access",
+ trace::Metric::Counter);
/// An LRU cache of idle ASTs.
/// Because we want to limit the overall number of these we retain, the cache
/// owns ASTs (and may evict them) while their workers are idle.
@@ -143,10 +146,14 @@
/// 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) {
+ // 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()) {
+ ASTCacheAccess.record(1, "miss");
return None;
+ }
+ ASTCacheAccess.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
Index: clang-tools-extra/clangd/ClangdServer.cpp
===================================================================
--- clang-tools-extra/clangd/ClangdServer.cpp
+++ 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>
@@ -361,6 +362,9 @@
WorkScheduler.runWithAST("PrepareRename", File, std::move(Action));
}
+// Tracks number of renamed symbols per invocation.
+constexpr trace::Metric RenamedSymbolCounts("renamed_symbol_counts",
+ trace::Metric::Distribution);
void ClangdServer::rename(PathRef File, Position Pos, llvm::StringRef NewName,
const RenameOptions &Opts, Callback<FileEdits> CB) {
// A snapshot of all file dirty buffers.
@@ -393,6 +397,7 @@
if (Err)
return CB(std::move(Err));
}
+ RenamedSymbolCounts.record(Edits->size());
return CB(std::move(*Edits));
};
WorkScheduler.runWithAST("Rename", File, std::move(Action));
@@ -420,6 +425,10 @@
return std::move(Result);
}
+// Tracks number of times a tweak has been offered. Label should be set to tweak
+// id.
+constexpr trace::Metric ShownCodeactions("shown_codeaction_count",
+ trace::Metric::Counter);
void ClangdServer::enumerateTweaks(PathRef File, Range Sel,
Callback<std::vector<TweakRef>> CB) {
auto Action = [File = File.str(), Sel, CB = std::move(CB),
@@ -439,6 +448,7 @@
for (auto &T : prepareTweaks(*Sel, Filter)) {
Res.push_back({T->id(), T->title(), T->intent()});
PreparedTweaks.insert(T->id());
+ ShownCodeactions.record(1, T->id());
}
}
@@ -449,6 +459,10 @@
TUScheduler::InvalidateOnUpdate);
}
+// Tracks number of times a tweak has been applied. Label should be set to tweak
+// id.
+constexpr trace::Metric ExecutedTweaks("executed_tweaks",
+ trace::Metric::Counter);
void ClangdServer::applyTweak(PathRef File, Range Sel, StringRef TweakID,
Callback<Tweak::Effect> CB) {
auto Action =
@@ -480,6 +494,7 @@
if (llvm::Error Err = reformatEdit(E, Style))
elog("Failed to format {0}: {1}", It.first(), std::move(Err));
}
+ ExecutedTweaks.record(1, TweakID);
}
return CB(std::move(*Effect));
};
Index: clang-tools-extra/clangd/ClangdLSPServer.cpp
===================================================================
--- clang-tools-extra/clangd/ClangdLSPServer.cpp
+++ clang-tools-extra/clangd/ClangdLSPServer.cpp
@@ -43,6 +43,10 @@
namespace clangd {
namespace {
+// Tracks end-to-end latency of high level lsp calls.
+constexpr trace::Metric LSPLatencies("lsp_latencies",
+ trace::Metric::Distribution);
+
// LSP defines file versions as numbers that increase.
// ClangdServer treats them as opaque and therefore uses strings instead.
std::string encodeVersion(int64_t LSPVersion) {
@@ -185,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, &LSPLatencies);
SPAN_ATTACH(Tracer, "Params", Params);
ReplyOnce Reply(ID, Method, &Server, Tracer.Args);
log("<-- {0}({1})", Method, ID);
@@ -297,7 +301,7 @@
elog("Failed to decode {0} request.", Method);
return;
}
- trace::Span Tracer(Method);
+ trace::Span Tracer(Method, &LSPLatencies);
SPAN_ATTACH(Tracer, "Params", RawParams);
(Server.*Handler)(P);
};
@@ -1288,7 +1292,7 @@
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);
@@ -1313,7 +1317,7 @@
SemanticTokensOrEdits Result;
{
std::lock_guard<std::mutex> Lock(SemanticTokensMutex);
- auto& Last = LastSemanticTokens[File];
+ auto &Last = LastSemanticTokens[File];
if (PrevResultID == Last.resultId) {
Result.edits = diffTokens(Last.tokens, Toks);
_______________________________________________
cfe-commits mailing list
cfe-commits@lists.llvm.org
https://lists.llvm.org/cgi-bin/mailman/listinfo/cfe-commits
