[clangd] Metric tracking through Tracer

[kadircet]

Summary

Introduces an endpoint to Tracer for tracking metrics on internal events.

[kadircet]

Extend tracer api to enable exporting metrics.

[kadircet]

• Report metrics on destruction.

[kadircet]

• Introduce latency tracking through context.
• Add metrics for code actions and rename.

[kadircet]

• Add tests

[sammccall]

Thanks for tackling this! Mostly API stuff, obviously :-)

clang-tools-extra/clangd/Trace.h

35 ↗

(On Diff #258595)

Conceptually there's a difference between a metric (the thing being measured, such as "latency distribution by method") and the measurement (such as "code completion took 90ms this time").
The attributes such as name, type, permitted labels are associated with the metric - these are schema. Whereas the measurement is a tuple (metric, actual label, value) - it doesn't make sense to have measurements for the same metric with different types. And the metric is immutable while the measurement is transient.

For the API (to emit data) it seems natural to model this split using constexpr objects for the metrics, and methods for the measurement:

constexpr Metric IncomingLatencyMS("/clangd/latency", Distribution);
...
void handleCodeCompletion() {
  ...
  IncomingLatencyMS.record(90);
}

(IOW I think our favorite metrics framework got this right)

For the SPI (to consume data), things are a bit muddier. For I think we want to avoid having a protocol to explicitly register metrics, so there's an attraction to just reporting the flat (name, type, label, value) tuple. I also quite like the idea of reusing the type above and reporting this as (const Metric&, label, value) which makes extending Metric more natural.

36 ↗

(On Diff #258595)

I think we're missing an important type: a value directly provided by the measurement, such as memory usage.

36 ↗

(On Diff #258595)

This enum is about defining the relationship between the metric and the measurements, but also about the (related) nature of the metric itself.

The current names are measurement-centric, which is good for the former but not so much for the latter, and a bit confusing if we set this enum when initializing the *metric*. I'd consider having this be metric-centric and documenting the measurements instead. e.g.

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,
};

42 ↗

(On Diff #258595)

An example to show the naming scheme?
I'd suggest just "method_latency" or so for most things - we can add "foo/bar" or "foo.bar" for hierarchy if needed, but I don't think a leading slash or a "clangd" in the path add anything.

46 ↗

(On Diff #258595)

(Not clear whether this is the allowed set of labels for a metric, bag of tags for a measurement, tuple of coordinates for a measurement...)

What are the design goals around labels? Can we make them as simple as possible (or remove them) for now?

Take the example of cache hit/miss.
There are at least two ways to model this without labels:

• cache.hit and cache.miss counters
• cache_hit distribution: measure 1 for hit, 0 for miss. Mean is the hit rate, count is the number of attempts.

The latter seems to capture the structure pretty well, but doesn't generalize (what if there are three categories?). The former seems almost equivalent to labels though.

Benefits of labels:

• part of the measurement, therefore can be dynamic (like filenames)
• explicit that it's meaningful to aggregate across labels (naming conventions are OK for this too for one dimension)
• generalizes sensibly to multiple dimensions (schema/docs become important)
• quoting/escaping is annoying for labels with funny characters (e.g. file paths)
• can bridge to other systems without knowledge of metric structure/semantics (this seems like a bad idea)

The first benefit seems pretty strong actually. I would suggest only supporting a single label though - it's a way simpler interface, we avoid complicated metrics whose schema might need documentation and enforcement, and we avoid any hint of memory allocation in the common case (just passing around a stringref that points to a literal, a filename we own, etc).

48 ↗

(On Diff #258595)

nit: since you have an unscoped enum, give the good name to the member and the bad name to the enum (which users need rarely spell)

57 ↗

(On Diff #258595)

Events we measure the duration of seem so closely related to trace spans that I don't think we can provide both without making it clear how they should relate to each other.

How horrible do you think it would be to have a second Metric* Measure = nullptr in the Span constructor?

It's hopelessly coupling together these two things that could otherwise be split, but...

[kadircet]

clang-tools-extra/clangd/Trace.h

35 ↗

(On Diff #258595)

this looks a lot better, thanks! Changing the order of label and value to make it nicer for non-labeled metrics.

36 ↗

(On Diff #258595)

I think we're missing an important type: a value directly provided by the measurement, such as memory usage.

I was planning to extend with this later on when we added memory tracking metrics.

[kadircet]

• Separate concept of a metric and measurement
• Tie latency tracking to trace::Spans.

[sammccall]

I like this a lot!

clang-tools-extra/clangd/ClangdLSPServer.cpp

46

comment should mention the label schema if it's not configured programmatically

(You could also do a trick of having a StringLiteral parameter for the label, even if all you store is bool WantsLabel or nothing at all)

46

units. We should decide whether units go in the metric name or just a comment.

47

nit: I'm not sure pluralizing metric names makes sense/is helpful, seems likely to make them less regular

clang-tools-extra/clangd/ClangdServer.cpp

366

We're not counting symbols, we're counting occurrences.
rename_occurrences?

366

static? and below

430

this is an internal name, mixing terminology seems unneccesary
tweak_available ?

I also like noun first then verb, so we get related metrics grouped alphabetically

463

suggest "tweak_success" or "tweak_attempt" depending on what we're measuring

474

we return early here, skipping the metric increment, but not for error-conditions below.

We should be either measuring attempts or successes, consistently.
(For attempts, can do this at the top of applyTweak)

496

nit: this should be outside the if

clang-tools-extra/clangd/TUScheduler.cpp

145–148

you could consider passing the metric in here so we can distinguish between retrieval for diagnostics and retrieval for actions

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

222

don't we want a catch-all metric so we get the existing span latencies in some form?

227

if we're recording floating point numbers, seconds seems less arbitrary than ms, and mayxe less prone to confusion

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

33–72

trace events and metric measurements....
, the measurements are produced by Metric::record().

53

define label here or as part of the class definition
(in particular, the idea that metrics are recorded per-label and also aggregated across all labels)

57

text says slashes, example has dots

83

now we have several logically-independent functions here, consider providing a no-op implementation (return Context::current().clone()) for this and the other methods (and remove them from the test)

94

event -> metric
exports -> records

131

units (suggest seconds)

132

I'd consider making these overloads so we don't have to use a pointer.

[kadircet]

• Address comments

[kadircet]

clang-tools-extra/clangd/ClangdLSPServer.cpp

46

(You could also do a trick of having a StringLiteral parameter for the label, even if all you store is bool WantsLabel or nothing at all)

did that and put an assertion to ensure labels are provided when needed and vice versa.

clang-tools-extra/clangd/ClangdServer.cpp

366

why? i thought constexpr already enforced internal linkage(at least for top level decls).

are you suggesting moving it into the function body and marking static constexpr?

474

yes i was trying to record only the successful executions. but attempts sounds better.

clang-tools-extra/clangd/TUScheduler.cpp

145–148

did that. apart from tracking read/diag access it is also important to not track accesses when we are trying to evict the cache.

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

222

i put a metric to track all spans that wasn't created with an explicit metric.

[sammccall]

Awesome, ship it!

... though, how do you feel about testing the actual metrics we export?

Suggest a slightly generalized TestTracer that installs itself (RAII), and has a

// Returns recorded values for a metric, and clears then.
vector<double> TestTracer::take(StringRef Metric, StringRef Label="");

Then it should be pretty simple to add assertions to a few existing tests.

clang-tools-extra/clangd/ClangdLSPServer.cpp

49

Nit: operation->method, as they're called in JSON-RPC

clang-tools-extra/clangd/ClangdServer.cpp

366

You're right, I was confused about constexpr.

That said, for the ones used inside one function, restricting the scope as you suggest seems nice.

(We can also inline them entirely if only used once, but maybe some level of consistency is better)

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

95

Remove the default argument here. Virtual + default is a little confusing and we're always going to pass it anyway

[kadircet]

• Test real metrics

[kadircet]

In D78429#2012873, @sammccall wrote:

Awesome, ship it!

... though, how do you feel about testing the actual metrics we export?

Suggest a slightly generalized TestTracer that installs itself (RAII), and has a

// Returns recorded values for a metric, and clears then.
vector<double> TestTracer::take(StringRef Metric, StringRef Label="");

Then it should be pretty simple to add assertions to a few existing tests.

Done, except tweak related metrics. We are not testing them through clangdserver, and i shied away from doing the plumbing :/ Let me know if you think it is important.

Also while writing the test for rename I've noticed we were actually counting renamed files rather than occurrences, had to put a loop that would go over each file, PTAL.

[sammccall]

Thanks!

In D78429#2013635, @kadircet wrote:

Also while writing the test for rename I've noticed we were actually counting renamed files rather than occurrences, had to put a loop that would go over each file, PTAL.

Oh, I'd forgotten this. This was actually deliberate IIRC, I think the idea was much of the "cost" of a large rename grows with files rather than occurrences, so the limit of 50 applies to files.
I'd probably leave as-is and rename the metric to rename_files, but up to you.

clang-tools-extra/clangd/unittests/ClangdLSPServerTests.cpp

159

nit: ElementsAre(_) or SizeIs(1)?

clang-tools-extra/clangd/unittests/TUSchedulerTests.cpp

523

SizeIs(0)/SizeIs(1) might be more expressive here

clang-tools-extra/clangd/unittests/TestTracer.h

36

ah, this should probably be takeMetric or so, because we might extend this class to cover non-metric tracing stuff.

(a slight misnomer, but "take measurement" collides with an english idiom and is also a bit unwieldy)

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

19

this needs a lock, the interface is documented as threadsafe.

[kadircet]

• Change IsEmpty with SizeIs
• Make TestTracer thread-safe

[kadircet]

• Track renamed files instead of occurences

[sammccall]

Still LG

clang-tools-extra/clangd/unittests/RenameTests.cpp

1047

I think this one should be elementsAre(2) though rather than just asserting that there's some measurement?

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

33

nit: vector's moved-from state is unspecified :-(

[hans]

For anyone running into the same problem, this broke the build with GCC 5:

/work/llvm.monorepo/clang-tools-extra/clangd/ClangdServer.cpp:374:75: error: could not convert ‘(const char*)""’ from ‘const char*’ to ‘llvm::StringLiteral’
                                                trace::Metric::Distribution);
                                                                           ^

Hopefully 3c2c7760d9eea0236c5c54e8939b3901f4208835 fixes it.

clang-tools-extra/clangd/ClangdLSPServer.cpp

 #include <mutex>
 #include <string>
 #include <vector>
 
 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) {
   return llvm::to_string(LSPVersion);
 }
 llvm::Optional<int64_t> decodeVersion(llvm::StringRef Encoded) {
   int64_t Result;
   if (llvm::to_integer(Encoded, Result, 10))
bool onNotify(llvm::StringRef Method, llvm::json::Value Params) override {
     return true;
   }
 
   bool onCall(llvm::StringRef Method, llvm::json::Value Params,
               llvm::json::Value ID) override {
     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);
     if (!Server.Server && Method != "initialize") {
       elog("Call {0} before initialization.", Method);
       Reply(llvm::make_error<LSPError>("server not initialized",
                                        ErrorCode::ServerNotInitialized));
     } else if (auto Handler = Calls.lookup(Method))
void bind(const char *Method,
             void (ClangdLSPServer::*Handler)(const Param &)) {
     Notifications[Method] = [Method, Handler,
                              this](llvm::json::Value RawParams) {
       Param P;
       if (!fromJSON(RawParams, P)) {
         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);
     };
   }
 
 private:
   // Function object to reply to an LSP call.
   // Each instance must be called exactly once, otherwise:
Server->semanticHighlights(
       [this, File(Params.textDocument.uri.file().str()), CB(std::move(CB))](
           llvm::Expected<std::vector<HighlightingToken>> HT) mutable {
         if (!HT)
           return CB(HT.takeError());
         SemanticTokens Result;
         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);
           Result.resultId = Last.resultId;
         }
         CB(std::move(Result));
       });
 }
 
 void ClangdLSPServer::onSemanticTokensEdits(
     const SemanticTokensEditsParams &Params,
     Callback<SemanticTokensOrEdits> CB) {
   Server->semanticHighlights(
       Params.textDocument.uri.file(),
       [this, PrevResultID(Params.previousResultId),
        File(Params.textDocument.uri.file().str()), CB(std::move(CB))](
           llvm::Expected<std::vector<HighlightingToken>> HT) mutable {
         if (!HT)
           return CB(HT.takeError());
         std::vector<SemanticToken> Toks = toSemanticTokens(*HT);
 
         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);
           } else {
             vlog("semanticTokens/edits: wanted edits vs {0} but last result "
                  "had ID {1}. Returning full token list.",
                  PrevResultID, Last.resultId);
             Result.tokens = Toks;

clang-tools-extra/clangd/ClangdServer.cpp

 #include "llvm/ADT/Optional.h"
 #include "llvm/ADT/STLExtras.h"
 #include "llvm/ADT/ScopeExit.h"
 #include "llvm/ADT/StringRef.h"
 #include "llvm/Support/Errc.h"
 #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>
 #include <memory>
 #include <mutex>
 #include <type_traits>
 
 namespace clang {
if (!Changes) {
       return CB(Changes.takeError());
     }
     return CB(Range);
   };
   WorkScheduler.runWithAST("PrepareRename", File, std::move(Action));
 }
 
 void ClangdServer::rename(PathRef File, Position Pos, llvm::StringRef NewName,
                           const RenameOptions &Opts, Callback<FileEdits> CB) {
   // A snapshot of all file dirty buffers.
   llvm::StringMap<std::string> Snapshot = WorkScheduler.getAllFileContents();
   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 =
         [&Snapshot](PathRef AbsPath) -> llvm::Optional<std::string> {
       auto It = Snapshot.find(AbsPath);
       if (It == Snapshot.end())
         return llvm::None;
       return It->second;
if (Opts.WantFormat) {
       llvm::Error Err = llvm::Error::success();
       for (auto &E : *Edits)
         Err =
             llvm::joinErrors(reformatEdit(E.getValue(), Style), std::move(Err));
 
       if (Err)
         return CB(std::move(Err));
     }
+    RenameFiles.record(Edits->size());
     return CB(std::move(*Edits));
   };
   WorkScheduler.runWithAST("Rename", File, std::move(Action));
 }
 
 // May generate several candidate selections, due to SelectionTree ambiguity.
 // vector of pointers because GCC doesn't like non-copyable Selection.
 static llvm::Expected<std::vector<std::unique_ptr<Tweak::Selection>>>
SelectionTree::createEach(
         return false;
       });
   assert(!Result.empty() && "Expected at least one SelectionTree");
   return std::move(Result);
 }
 
 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)
       return CB(InpAST.takeError());
     auto Selections = tweakSelection(Sel, *InpAST);
     if (!Selections)
       return CB(Selections.takeError());
     std::vector<TweakRef> Res;
     // Don't allow a tweak to fire more than once across ambiguous selections.
     llvm::DenseSet<llvm::StringRef> PreparedTweaks;
     auto Filter = [&](const Tweak &T) {
       return TweakFilter(T) && !PreparedTweaks.count(T.id());
     };
     for (const auto &Sel : *Selections) {
       for (auto &T : prepareTweaks(*Sel, Filter)) {
         Res.push_back({T->id(), T->title(), T->intent()});
         PreparedTweaks.insert(T->id());
+        TweakAvailable.record(1, T->id());
       }
     }
 
     CB(std::move(Res));
   };
 
   WorkScheduler.runWithAST("EnumerateTweaks", File, std::move(Action),
                            TUScheduler::InvalidateOnUpdate);
 }
 
 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 {
         if (!InpAST)
           return CB(InpAST.takeError());
         auto Selections = tweakSelection(Sel, *InpAST);
         if (!Selections)
           return CB(Selections.takeError());
         llvm::Optional<llvm::Expected<Tweak::Effect>> Effect;
         // Try each selection, take the first one that prepare()s.
         // If they all fail, Effect will hold get the last error.
         for (const auto &Selection : *Selections) {
           auto T = prepareTweak(TweakID, *Selection);
           if (T) {
             Effect = (*T)->apply(*Selection);
             break;
           }
           Effect = T.takeError();
         }
         assert(Effect.hasValue() && "Expected at least one selection");
         if (*Effect) {
           // Tweaks don't apply clang-format, do that centrally here.
           for (auto &It : (*Effect)->ApplyEdits) {
             Edit &E = It.second;
             format::FormatStyle Style =
                 getFormatStyleForFile(File, E.InitialCode, FS.get());
             if (llvm::Error Err = reformatEdit(E, Style))
               elog("Failed to format {0}: {1}", It.first(), std::move(Err));
           }
         }
         return CB(std::move(*Effect));
       };
   WorkScheduler.runWithAST("ApplyTweak", File, std::move(Action));
 }
 
 void ClangdServer::dumpAST(PathRef File,
                            llvm::unique_function<void(std::string)> Callback) {
   auto Action = [Callback = std::move(Callback)](

clang-tools-extra/clangd/TUScheduler.cpp

void put(Key K, std::unique_ptr<ParsedAST> V) {
     // Run the expensive destructor outside the lock.
     Lock.unlock();
     ForCleanup.reset();
   }
 
   /// 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
     // constructor of unique_ptr, so we call the move ctor explicitly to avoid
     // this miscompile.
     return llvm::Optional<std::unique_ptr<ParsedAST>>(std::move(V));
   }
 
void ASTWorker::update(ParseInputs Inputs, WantDiagnostics WantDiags) {
   };
   startTask(TaskName, std::move(Task), WantDiags, TUScheduler::NoInvalidation);
 }
 
 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 =
           buildCompilerInvocation(FileInputs, CompilerInvocationDiagConsumer);
       // Try rebuilding the AST.
       vlog("ASTWorker rebuilding evicted AST to run {0}: {1} version {2}", Name,
            FileName, FileInputs.Version);
       // FIXME: We might need to build a patched ast once preamble thread starts
PreambleRequests.push({std::move(Task), std::move(TaskName),
                            llvm::None, TUScheduler::NoInvalidation, nullptr});
   }
   RequestsCV.notify_all();
 }
 
 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.
   {
     std::lock_guard<std::mutex> Lock(PublishMu);
     if (!CanPublishResults)
       return;
   }
   // Used to check whether we can update AST cache.
void ASTWorker::generateDiagnostics(
   std::string TaskName = llvm::formatv("Build AST ({0})", Inputs.Version);
   Status.update([&](TUStatus &Status) {
     Status.ASTActivity.K = ASTAction::Building;
     Status.ASTActivity.Name = std::move(TaskName);
   });
   // 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(
         FileName, Inputs, std::move(Invocation), CIDiags, LatestPreamble);
     auto RebuildDuration = DebouncePolicy::clock::now() - RebuildStartTime;
     ++ASTBuildCount;
     // Try to record the AST-build time, to inform future update debouncing.
     // This is best-effort only: if the lock is held, don't bother.

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

 // All APIs are no-ops unless a Session is active (created by ClangdMain).
 //
 //===----------------------------------------------------------------------===//
 
 #ifndef LLVM_CLANG_TOOLS_EXTRA_CLANGD_SUPPORT_TRACE_H_
 #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:
   virtual ~EventTracer() = default;
 
   /// Called when event that has a duration starts. \p Name describes the event.
   /// Returns a derived context that will be destroyed when the event ends.
   /// 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
 /// trace::log. Only one TracingSession can be active at a time and it should be
 /// set up before calling any clangd-specific functions.
 class Session {
 public:
   Session(EventTracer &Tracer);

 ///
 /// Arbitrary JSON metadata can be attached while this span is active:
 ///   SPAN_ATTACH(MySpan, "Payload", SomeJSONExpr);
 ///
 /// SomeJSONExpr is evaluated and copied only if actually needed.
 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.
   /// Prefer to use SPAN_ATTACH rather than accessing this directly.
   /// The lifetime of Args is the whole event, even if the Span dies.
   llvm::json::Object *const Args;
 
 private:

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

 //===--- Trace.cpp - Performance tracing facilities -----------------------===//
 //
 // 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 "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 {
 namespace clangd {
 namespace trace {
 
 namespace {
 // The current implementation is naive: each thread writes to Out guarded by Mu.

 
 void log(const llvm::Twine &Message) {
   if (!T)
     return;
   T->instant("Log", llvm::json::Object{{"Message", Message.str()}});
 }
 
 // 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

clang-tools-extra/clangd/unittests/CMakeLists.txt

add_unittest(ClangdUnitTests ClangdTests
   TweakTesting.cpp
   URITests.cpp
   XRefsTests.cpp
 
   support/CancellationTests.cpp
   support/ContextTests.cpp
   support/FunctionTests.cpp
   support/ThreadingTests.cpp
+  support/TestTracer.cpp
   support/TraceTests.cpp
 
   $<TARGET_OBJECTS:obj.clangDaemonTweaks>
   )
 
 clang_target_link_libraries(ClangdTests
   PRIVATE
   clangAST

clang-tools-extra/clangd/unittests/ClangdLSPServerTests.cpp

 //===-- ClangdLSPServerTests.cpp ------------------------------------------===//
 //
 // 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 "Annotations.h"
 #include "ClangdLSPServer.h"
 #include "CodeComplete.h"
 #include "LSPClient.h"
 #include "Protocol.h"
 #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"
 #include "gtest/gtest.h"
 
 namespace clang {
 namespace clangd {
 namespace {
Client.notify(
       "textDocument/didSave",
       llvm::json::Object{{"textDocument", Client.documentID("foo.h")}});
   // Foo.cpp should be rebuilt with new diagnostics.
   EXPECT_THAT(Client.diagnostics("foo.cpp"),
               llvm::ValueIs(testing::ElementsAre(
                   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

clang-tools-extra/clangd/unittests/LSPClient.cpp

 
 llvm::Expected<llvm::json::Value> clang::clangd::LSPClient::CallResult::take() {
   std::unique_lock<std::mutex> Lock(Mu);
   if (!clangd::wait(Lock, CV, timeoutSeconds(10),
                     [this] { return Value.hasValue(); })) {
     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() {
   auto ExpValue = take();
   if (!ExpValue) {
     ADD_FAILURE() << "takeValue(): " << llvm::toString(ExpValue.takeError());
     return llvm::json::Value(nullptr);
   }

clang-tools-extra/clangd/unittests/RenameTests.cpp

 //===-- RenameTests.cpp -----------------------------------------*- 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 "Annotations.h"
 #include "ClangdServer.h"
 #include "SyncAPI.h"
 #include "TestFS.h"
 #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"
 #include "gmock/gmock.h"
 #include "gtest/gtest.h"
 #include <algorithm>
 
 namespace clang {
 namespace clangd {
 namespace {
 
 using testing::Eq;
-using testing::Pair;
 using testing::IsEmpty;
+using testing::Pair;
+using testing::SizeIs;
 using testing::UnorderedElementsAre;
 using testing::UnorderedElementsAreArray;
 
 // Convert a Range to a Ref.
 Ref refWithRange(const clangd::Range &Range, const std::string &URI) {
   Ref Result;
   Result.Kind = RefKind::Reference | RefKind::Spelled;
   Result.Location.Start.setLine(Range.start.line);
llvm::StringRef FooCC;
           [[Foo]] x;
           FOO y;
           FooFoo z;
         }
       )cpp",
       },
   };
 
-  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);
     std::string FooHPath = testPath("foo.h");
     std::string FooCCPath = testPath("foo.cc");
 
     MockFSProvider FS;
     FS.Files[FooHPath] = std::string(FooH.code());
     FS.Files[FooCCPath] = std::string(FooCC.code());
 
     auto ServerOpts = ClangdServer::optsForTest();
     ServerOpts.BuildDynamicSymbolIndex = true;
     ClangdServer Server(CDB, FS, ServerOpts);
 
     // Add all files to clangd server to make sure the dynamic index has been
     // built.
     runAddDocument(Server, FooHPath, FooH.code());
     runAddDocument(Server, FooCCPath, FooCC.code());
 
     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"), SizeIs(1));
       EXPECT_THAT(
           applyEdits(std::move(FileEditsList)),
           UnorderedElementsAre(
               Pair(Eq(FooHPath), Eq(expectedResult(T.FooH, NewName))),
               Pair(Eq(FooCCPath), Eq(expectedResult(T.FooCC, NewName)))));
     }
   }
 }

clang-tools-extra/clangd/unittests/TUSchedulerTests.cpp

 #include "Matchers.h"
 #include "ParsedAST.h"
 #include "Preamble.h"
 #include "TUScheduler.h"
 #include "TestFS.h"
 #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"
 #include "llvm/ADT/STLExtras.h"
 #include "llvm/ADT/ScopeExit.h"
 #include "gmock/gmock.h"
 #include "gtest/gtest.h"
 #include <algorithm>
 #include <atomic>
 #include <chrono>
 #include <cstdint>
 #include <utility>
 
 namespace clang {
 namespace clangd {
 namespace {
 
 using ::testing::AnyOf;
 using ::testing::Each;
 using ::testing::ElementsAre;
 using ::testing::Eq;
 using ::testing::Field;
 using ::testing::IsEmpty;
 using ::testing::Pointee;
+using ::testing::SizeIs;
 using ::testing::UnorderedElementsAre;
 
 MATCHER_P2(TUState, PreambleActivity, ASTActivity, "") {
   if (arg.PreambleActivity != PreambleActivity) {
     *result_listener << "preamblestate is "
                      << static_cast<uint8_t>(arg.PreambleActivity);
     return false;
   }
TEST_F(TUSchedulerTests, ManyUpdates) {
   EXPECT_EQ(TotalPreambleReads, FilesCount * UpdatesPerFile);
 }
 
 TEST_F(TUSchedulerTests, EvictedAST) {
   std::atomic<int> BuiltASTCounter(0);
   auto Opts = optsForTest();
   Opts.AsyncThreadsCount = 1;
   Opts.RetentionPolicy.MaxRetainedASTs = 2;
+  trace::TestTracer Tracer;
   TUScheduler S(CDB, Opts);
 
   llvm::StringLiteral SourceContents = R"cpp(
     int* a;
     double* b = a;
   )cpp";
   llvm::StringLiteral OtherSourceContents = R"cpp(
     int* a;
     double* b = a + 0;
   )cpp";
 
   auto Foo = testPath("foo.cpp");
   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.
   updateWithCallback(S, Bar, SourceContents, WantDiagnostics::Yes,
                      [&BuiltASTCounter]() { ++BuiltASTCounter; });
   updateWithCallback(S, Baz, SourceContents, WantDiagnostics::Yes,
                      [&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));
 
   // Access the old file again.
   updateWithCallback(S, Foo, OtherSourceContents, WantDiagnostics::Yes,
                      [&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.
   EXPECT_THAT(S.getFilesWithCachedAST(),
               UnorderedElementsAre(Foo, AnyOf(Bar, Baz)));
 }
 
 // We send "empty" changes to TUScheduler when we think some external event
updateWithDiags(S, Source, Inputs, WantDiagnostics::Yes,
                     ++DiagCount;
                     EXPECT_THAT(Diags, IsEmpty());
                   });
 
   ASSERT_TRUE(S.blockUntilIdle(timeoutSeconds(10)));
   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."; });
   S.runWithAST("touchAST", FooCpp, [](Expected<InputsAndAST> IA) {
     // Make sure the AST was actually built.
     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.
   std::atomic<bool> SeenDiags(false);
   updateWithDiags(S, FooCpp, Contents, WantDiagnostics::Auto,
                   [&](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.
   updateWithDiags(
       S, FooCpp, Contents, WantDiagnostics::Auto,
       [&](std::vector<Diag>) { ADD_FAILURE() << "Should not be called."; });
   ASSERT_TRUE(S.blockUntilIdle(timeoutSeconds(10)));
 }

clang-tools-extra/clangd/unittests/TestTracer.h

+//===-- 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

clang-tools-extra/clangd/unittests/support/TestTracer.h

+//===-- 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

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

+//===-- 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 {};
+  return std::move(ValuesIt->getValue());
+}
+} // namespace trace
+} // namespace clangd
+} // namespace clang

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

 //===-- TraceTests.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 "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"
 #include "gmock/gmock.h"
 #include "gtest/gtest.h"
 
 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();
     return false;
   }
   llvm::SmallString<32> S;
   return Val == static_cast<llvm::yaml::ScalarNode *>(arg)->getValue(S);
 }
TEST(TraceTest, SmokeTest) {
   ASSERT_NE(++Event, Events->end()) << "Expected log message";
   EXPECT_TRUE(VerifyObject(*Event, {{"ph", "i"}, {"name", "Log"}}));
   ASSERT_NE(++Event, Events->end()) << "Expected span end";
   EXPECT_TRUE(VerifyObject(*Event, {{"ph", "X"}, {"name", "A"}}));
   ASSERT_EQ(++Event, Events->end());
   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