[clangd] Changed tracing interfaces

[ilya-biryukov]

Summary

EventTracer interface now contains two methods:

• spanEvent for events that have duration,
• instant for events that are instant.

[luckygeck]

clangd/Trace.h

41

This is a (1)static non-pod member in an (2) interface. Is it really a good idea? If we plan to have only one ctxkey, then maybe let's make it not bound to EventTracer?

45

s/stars/starts.

49

Maybe it is better to calculate these Args only if the tracing is enabled? This might be done at least this two ways:

1. Have bool is_tracing_enabled() method that we can check before calculating args.
2. Pass a function that will produce json::obj when called.

[ilya-biryukov]

• Fixed a typo.

[ilya-biryukov]

clangd/Trace.h

41

It does not have any data members, has trivial default constructor and trivial destructor.
I don't think there are any problems we're gonna hit with this one, or am I missing something?

then maybe let's make it not bound to EventTracer?

Do you propose to move it out of the class into the clangd::trace namespace instead?

49

The current implementation won't compute args if EventTracer inside a Context is null, so I think this should cover our needs for per-request tracing (see SPAN_ATTACH macro).
But is_tracing_enabled() makes sense if we'd like to turn the tracing off in a middle of a single Context lifetime. This would make sense for global tracer, is this the use-case you anticipate?

[luckygeck]

clangd/Trace.h

41

I've just looked through the change adding Context and Key<>\PtrKey<> thingy. Yes, these classes are POD, so it is fine to have them static (as you rely only on their address).

Yes, I'd prefer to move the key out of class into a namespace - interface looks better without any data IMO.

49

Oh, ok - setting tracer in a context only when we need to looks good enough.

[ilya-biryukov]

Have to update to match the new Context implementation.

[ilya-biryukov]

• Update the patch to accomodate changes from tracing and Context patches.

[sammccall]

clangd/Trace.cpp

135–136

why not?

clangd/Trace.h

40

just call this begin?
Otherwise style is beginEvent I think

42

How is identity represented between begin/end event? via Name doesn't seem robust, so why the need to pass it twice? Does providing different contexts for start/end make sense?

It might be cleaner/more flexible to have

std::function<void(json::obj&&)> begin()
and call the return value to signal end.

This seems likely to be pretty easy for different providers to implement, and is easy to use from Span.

[ilya-biryukov]

clangd/Trace.cpp

135–136

Because T must outlive the Span, so we can't really have if (!T) evaluate to different things in constructor and destructor.
Am I missing something?

[sammccall]

clangd/Trace.cpp

135–136

I was being disingenuous, I agree with you.
But can you change the message to "Changed tracer during a span"?

assert(Args) and "Args can't be null at this point" are basically synonyms :-)

[ilya-biryukov]

• Update the patch to accomodate changes from tracing and Context patches.
• Updated tracing after changes to Context. We now store a clone() of Context in Span instead of ContextData.
• Pass Context by const-ref instead of by ref.

[ilya-biryukov]

Updated the patch after changes to Context

[ilya-biryukov]

• Changed the EventTracer interface to return a callback from beginEvent instead of using begin_event/end_event method pairs.

clangd/Trace.h

40

The new name is beginSpan. Hope that sounds good.

42

Done. As discussed offline, the interface you propose seems much nicer.
Used names beginSpan and instant.

[sammccall]

clangd/Trace.cpp

128

I'm not sure this is useful. Tracers that aren't interested in args can't opt out by providing a null callback, unless they also don't care about the end time.
This seems unlikely (a null tracer, I guess)

[ilya-biryukov]

clangd/Trace.cpp

128

One use-case that came to mind is turning the tracing on or off on per-request basis

[ilya-biryukov]

Merged with head

clangd/Trace.h

 #include "JSONExpr.h"
 #include "llvm/ADT/Twine.h"
 #include "llvm/Support/raw_ostream.h"
 
 namespace clang {
 namespace clangd {
 namespace trace {
 
+/// A sink for consuming tracing events. Calls to begin_event and end_event with
+/// the same name are always properly nested by using a RAII object (Span).
+/// However, global tracers (i.e., returned from the global Context object) may
+/// be called concurrently and have to be properly synchronized. For per-request
+/// EventTracers (i.e., returned from the request-specific Context objects) the
+/// calls to begin_event and end_event must be properly synchronized and must
+/// never be called concurrently.
 class EventTracer {
 public:
+  /// A key used by trace::Span and trace::log to find EventTracer in a \p
+  /// Context.
   static PtrKey<EventTracer> CtxKey;
 
   virtual ~EventTracer() = default;
-  virtual void event(llvm::StringRef Phase, json::obj &&Contents) = 0;
+
+  /// Called when event with \p Name starts.
+  virtual void begin_event(Context &Ctx, llvm::StringRef Name) = 0;
+  /// Called when event with \p Name ends.
+  virtual void end_event(Context &Ctx, llvm::StringRef Name,
+                         json::obj &&Args) = 0;
+  /// Called for instant events.
+  virtual void instant_event(Context &Ctx, llvm::StringRef Name,
+                             json::obj &&Args) = 0;
 };
 
 /// Create an instance of EventTracer that produces an output in the Trace Event
 /// format supported by Chrome's trace viewer (chrome://tracing).
 ///
 /// The format is documented here:
 /// https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview
 ///
public:
   ~Span();
 
   /// Returns mutable span metadata if this span is interested.
   /// Prefer to use SPAN_ATTACH rather than accessing this directly.
   json::obj *args() { return Args.get(); }
 
 private:
   Context &Ctx;
+  std::string Name;
   std::unique_ptr<json::obj> Args;
 };
 
 #define SPAN_ATTACH(S, Name, Expr)                                             \
   do {                                                                         \
     if ((S).args() != nullptr) {                                               \
       (*((S).args()))[(Name)] = (Expr);                                        \
     }                                                                          \
   } while (0)
 
 } // namespace trace
 } // namespace clangd
 } // namespace clang
 
 #endif // LLVM_CLANG_TOOLS_EXTRA_CLANGD_TRACE_H_

clangd/Trace.cpp

rawEvent("M", json::obj{
                   });
   }
 
   ~JSONTracer() {
     Out << "\n]}";
     Out.flush();
   }
 
+  void begin_event(Context &Ctx, llvm::StringRef Name) override {
+    jsonEvent("B", json::obj{{"name", Name}});
+  }
+
+  void end_event(Context &Ctx, llvm::StringRef Name,
+                 json::obj &&Args) override {
+    jsonEvent("E", json::obj{{"name", Name}, {"args", std::move(Args)}});
+  }
+
+  void instant_event(Context &Ctx, llvm::StringRef Name,
+                     json::obj &&Args) override {
+    jsonEvent("i", json::obj{{"name", Name}, {"args", std::move(Args)}});
+  }
+
   // Record an event on the current thread. ph, pid, tid, ts are set.
   // Contents must be a list of the other JSON key/values.
-  void event(StringRef Phase, json::obj &&Contents) override {
+  void jsonEvent(StringRef Phase, json::obj &&Contents) {
     uint64_t TID = get_threadid();
     std::lock_guard<std::mutex> Lock(Mu);
     // If we haven't already, emit metadata describing this thread.
     if (ThreadsWithMD.insert(TID).second) {
       SmallString<32> Name;
       get_thread_name(Name);
       if (!Name.empty()) {
         rawEvent("M", json::obj{
std::unique_ptr<EventTracer> createJSONTracer(llvm::raw_ostream &OS,
                                               bool Pretty) {
   return llvm::make_unique<JSONTracer>(OS, Pretty);
 }
 
 void log(Context &Ctx, const Twine &Message) {
   EventTracer *T = Ctx.get(EventTracer::CtxKey);
   if (!T)
     return;
-  T->event("i", json::obj{
-                    {"name", "Log"},
-                    {"args", json::obj{{"Message", Message.str()}}},
-                });
+  T->instant_event("Log", json::obj{{"Message", Message.str()}});
 }
 
-Span::Span(Context &Ctx, std::string Name) : Ctx(Ctx) {
-  EventTracer* T = Ctx.get(EventTracer::CtxKey);
+Span::Span(Context &Ctx, std::string Name) : Ctx(Ctx), Name(std::move(Name)) {
+  EventTracer *T = Ctx.get(EventTracer::CtxKey);
   if (!T)
     return;
-  T->event("B", json::obj{{"name", std::move(Name)}});
+  T->begin_event(this->Name);
   Args = llvm::make_unique<json::obj>();
 }
 
 Span::~Span() {
   auto T = Ctx.get(EventTracer::CtxKey);
   if (!T)
     return;
-  if (!Args)
-    Args = llvm::make_unique<json::obj>();
-  T->event("E", Args ? json::obj{{"args", std::move(*Args)}} : json::obj{});
+  assert(Args && "Args can't be null at this point");
+  T->end_event(Name, std::move(*Args));
 }
 
 } // namespace trace
 } // namespace clangd
 } // namespace clang