[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

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

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

36

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

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

(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

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

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

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

36

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

369

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

369

static? and below

432

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

465

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

472–476

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)

498

nit: this should be outside the if

clang-tools-extra/clangd/TUScheduler.cpp

145–149

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 ↗

(On Diff #261156)

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

227 ↗

(On Diff #261156)

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

53 ↗

(On Diff #261156)

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 ↗

(On Diff #261156)

text says slashes, example has dots

62 ↗

(On Diff #261156)

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

73 ↗

(On Diff #261156)

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)

84 ↗

(On Diff #261156)

event -> metric
exports -> records

121 ↗

(On Diff #261156)

units (suggest seconds)

122 ↗

(On Diff #261156)

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

369

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?

472–476

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

clang-tools-extra/clangd/TUScheduler.cpp

145–149

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 ↗

(On Diff #261156)

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

369

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 ↗

(On Diff #261208)

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 ↗

(On Diff #261329)

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

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

522 ↗

(On Diff #261329)

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

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

35 ↗

(On Diff #261329)

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

18 ↗

(On Diff #261329)

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 ↗

(On Diff #261514)

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 ↗

(On Diff #261514)

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 {
 
 // 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))
     return Result;
   else if (!Encoded.empty()) // Empty can be e.g. diagnostics on close.
     elog("unexpected non-numeric version {0}", Encoded);
   return llvm::None;
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));
+    WithContext LatencyCtx(trace::latencyTrackingContext(Method));
     trace::Span Tracer(Method);
     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));
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);
       SPAN_ATTACH(Tracer, "Params", RawParams);
+      WithContext LatencyCtx(trace::latencyTrackingContext(Method));
       (Server.*Handler)(P);
     };
   }
 
 private:
   // Function object to reply to an LSP call.
   // Each instance must be called exactly once, otherwise:
   //  - the bug is logged, and (in debug mode) an assert will fire

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 {
     if (!InpAST)
       return CB(InpAST.takeError());
     auto GetDirtyBuffer =
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));
     }
+    trace::Metric M("/clangd/rename");
+    M.Ty = trace::Metric::Sample;
+    M.Value = 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) {
   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());
+        trace::Metric M("/clangd/shown_codeaction");
+        M.Ty = trace::Metric::Increment;
+        M.Value = 1;
+        M.Labels = {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) {
   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());
+        trace::Metric M("/clangd/executed_tweaks");
+        M.Ty = trace::Metric::Increment;
+        M.Value = 1;
+        M.Labels = {TweakID, /*Error=*/""};
         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));
+        }
+        auto Err = Effect->takeError();
+        M.Labels.back() = llvm::to_string(Err);
+        return CB(std::move(Err));
       };
   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)](
                     llvm::Expected<InputsAndAST> InpAST) mutable {

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) {
+    trace::Metric M("/clangd/ast_cache");
+    M.Ty = trace::Metric::Increment;
+    M.Value = 1;
+    // 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()) {
+      M.Labels = {"miss"};
       return None;
+    }
+    M.Labels = {"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));
   }
 

clang-tools-extra/clangd/Trace.h

 // All APIs are no-ops unless a Session is active (created by ClangdMain).
 //
 //===----------------------------------------------------------------------===//
 
 #ifndef LLVM_CLANG_TOOLS_EXTRA_CLANGD_TRACE_H_
 #define LLVM_CLANG_TOOLS_EXTRA_CLANGD_TRACE_H_
 
 #include "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. Reports
+/// itself to active tracer on destruction.
+struct Metric {
+  enum Type {
+    /// Occurence of an event, e.g. cache access.
+    Increment,
+    /// Aspect of an event, e.g. number of symbols in an index lookup.
+    Sample,
+  };
+  /// Uniquely identifies the metric.
+  const llvm::StringLiteral Name;
+  /// Divides a metric into meaningful parts. e.g. hit/miss to represent result
+  /// of a cache access.
+  std::vector<std::string> Labels;
+  double Value = 0;
+  Type Ty;
+
+  Metric(llvm::StringLiteral Name) : Name(Name) {}
+  Metric(const Metric &) = delete;
+  Metric &operator=(const Metric &) = delete;
+  ~Metric();
+};
+
+/// Creates a context that will report its duration as a metric on destruction.
+Context latencyTrackingContext(llvm::StringRef OpName);
+
 /// A consumer of trace events. The events are produced by Spans and trace::log.
 /// 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;
   // 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(){};
 
   /// 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) {}
 };
 
 /// 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);

clang-tools-extra/clangd/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 "Trace.h"
 #include "Context.h"
 #include "llvm/ADT/DenseSet.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.
private:
   };
   static Key<std::unique_ptr<JSONSpan>> SpanKey;
 
   // Record an event. ph and pid are set.
   // Contents must be a list of the other JSON key/values.
   void rawEvent(llvm::StringRef Phase,
                 const llvm::json::Object &Event) /*REQUIRES(Mu)*/ {
     // PID 0 represents the clangd process.
-    Out.object([&]{
+    Out.object([&] {
       Out.attribute("pid", 0);
       Out.attribute("ph", Phase);
-      for (const auto& KV : Event)
+      for (const auto &KV : Event)
         Out.attribute(KV.first, KV.second);
     });
   }
 
   // If we haven't already, emit metadata describing this thread.
   void captureThreadMetadata() {
     uint64_t TID = llvm::get_threadid();
     std::lock_guard<std::mutex> Lock(Mu);
Span::Span(llvm::Twine Name)
     : Args(T ? new llvm::json::Object() : nullptr),
       RestoreCtx(makeSpanContext(Name, Args)) {}
 
 Span::~Span() {
   if (T)
     T->endSpan();
 }
 
+Metric::~Metric() {
+  if (!T)
+    return;
+  T->record(*this);
+}
+
+Context latencyTrackingContext(llvm::StringRef OpName) {
+  using Clock = std::chrono::high_resolution_clock;
+  return Context::current().derive(
+      llvm::make_scope_exit([StartTime = Clock::now(), OpName = OpName.str()] {
+        Metric M("/clangd/latencies");
+        M.Value = std::chrono::duration_cast<std::chrono::milliseconds>(
+                      Clock::now() - StartTime)
+                      .count();
+        M.Labels = {OpName};
+        M.Ty = Metric::Sample;
+      }));
+}
+
 } // namespace trace
 } // namespace clangd
 } // namespace clang

clang-tools-extra/clangd/unittests/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 "Context.h"
 #include "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 {
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());
 }
 
+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) 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, SendsOnDestruct) {
+  const llvm::StringLiteral MetricName = "/test/metric";
+  {
+    trace::Metric M{MetricName};
+    EXPECT_THAT(Metrics, testing::IsEmpty());
+  }
+  EXPECT_THAT(Metrics, testing::ElementsAre(MetricName));
+}
+
+TEST_F(MetricsTracerTest, LatencyTest) {
+  const llvm::StringLiteral MetricName = "/clangd/latencies";
+  {
+    WithContext Ctx(trace::latencyTrackingContext("op_name"));
+    EXPECT_THAT(Metrics, testing::IsEmpty());
+  }
+  EXPECT_THAT(Metrics, testing::ElementsAre(MetricName));
+}
+
 } // namespace
 } // namespace clangd
 } // namespace clang