[clang-tools-extra] fed995e - [clangd] Trace queue state for each TUScheduler action.

[Sam McCall via cfe-commits]

Author: Sam McCall
Date: 2021-02-05T17:56:51+01:00
New Revision: fed995ef9020ef2845ff78e9f4aa97e6d512c586

URL: https://github.com/llvm/llvm-project/commit/fed995ef9020ef2845ff78e9f4aa97e6d512c586
DIFF: https://github.com/llvm/llvm-project/commit/fed995ef9020ef2845ff78e9f4aa97e6d512c586.diff

LOG: [clangd] Trace queue state for each TUScheduler action.

The new trace event includes what's already in the queue when adding.
For tracers that follow contexts, the trace event will span the time that the action
spends in the queue.
For tracers that follow threads, the trace will be a tiny span on the enqueuing thread.

Differential Revision: https://reviews.llvm.org/D96027

Added: 
    

Modified: 
    clang-tools-extra/clangd/TUScheduler.cpp

Removed: 
    


################################################################################
diff  --git a/clang-tools-extra/clangd/TUScheduler.cpp b/clang-tools-extra/clangd/TUScheduler.cpp
index dd4312c4a7c2..26bf430db46f 100644
--- a/clang-tools-extra/clangd/TUScheduler.cpp
+++ b/clang-tools-extra/clangd/TUScheduler.cpp
@@ -465,6 +465,7 @@ class ASTWorker {
     std::string Name;
     steady_clock::time_point AddTime;
     Context Ctx;
+    llvm::Optional<Context> QueueCtx;
     llvm::Optional<UpdateType> Update;
     TUScheduler::ASTActionInvalidation InvalidationPolicy;
     Canceler Invalidate;
@@ -507,7 +508,7 @@ class ASTWorker {
   /// None means no builds yet, null means there was an error while building.
   /// Only written by ASTWorker's thread.
   llvm::Optional<std::shared_ptr<const PreambleData>> LatestPreamble;
-  std::queue<Request> PreambleRequests; /* GUARDED_BY(Mutex) */
+  std::deque<Request> PreambleRequests; /* GUARDED_BY(Mutex) */
   /// Signaled whenever LatestPreamble changes state or there's a new
   /// PreambleRequest.
   mutable std::condition_variable PreambleCV;
@@ -826,9 +827,10 @@ void ASTWorker::updatePreamble(std::unique_ptr<CompilerInvocation> CI,
   }
   {
     std::lock_guard<std::mutex> Lock(Mutex);
-    PreambleRequests.push({std::move(Task), std::move(TaskName),
-                           steady_clock::now(), Context::current().clone(),
-                           llvm::None, TUScheduler::NoInvalidation, nullptr});
+    PreambleRequests.push_back({std::move(Task), std::move(TaskName),
+                                steady_clock::now(), Context::current().clone(),
+                                llvm::None, llvm::None,
+                                TUScheduler::NoInvalidation, nullptr});
   }
   PreambleCV.notify_all();
   RequestsCV.notify_all();
@@ -1023,9 +1025,34 @@ void ASTWorker::startTask(llvm::StringRef Name,
       std::tie(Ctx, Invalidate) = cancelableTask(
           /*Reason=*/static_cast<int>(ErrorCode::ContentModified));
     }
+    // Trace the time the request spends in the queue, and the requests that
+    // it's going to wait for.
+    llvm::Optional<Context> QueueCtx;
+    if (trace::enabled()) {
+      // Tracers that follow threads and need strict nesting will see a tiny
+      // instantaneous event "we're enqueueing", and sometime later it runs.
+      WithContext WC(Ctx.clone());
+      trace::Span Tracer("Queued:" + Name);
+      if (Tracer.Args) {
+        if (CurrentRequest)
+          SPAN_ATTACH(Tracer, "CurrentRequest", CurrentRequest->Name);
+        llvm::json::Array PreambleRequestsNames;
+        for (const auto &Req : PreambleRequests)
+          PreambleRequestsNames.push_back(Req.Name);
+        SPAN_ATTACH(Tracer, "PreambleRequestsNames",
+                    std::move(PreambleRequestsNames));
+        llvm::json::Array RequestsNames;
+        for (const auto &Req : Requests)
+          RequestsNames.push_back(Req.Name);
+        SPAN_ATTACH(Tracer, "RequestsNames", std::move(RequestsNames));
+      }
+      // For tracers that follow contexts, keep the trace span's context alive
+      // until we dequeue the request, so they see the full duration.
+      QueueCtx = Context::current().clone();
+    }
     Requests.push_back({std::move(Task), std::string(Name), steady_clock::now(),
-                        std::move(Ctx), Update, Invalidation,
-                        std::move(Invalidate)});
+                        std::move(Ctx), std::move(QueueCtx), Update,
+                        Invalidation, std::move(Invalidate)});
   }
   RequestsCV.notify_all();
 }
@@ -1071,13 +1098,16 @@ void ASTWorker::run() {
       // Requests.front(), so prefer them first to preserve LSP order.
       if (!PreambleRequests.empty()) {
         CurrentRequest = std::move(PreambleRequests.front());
-        PreambleRequests.pop();
+        PreambleRequests.pop_front();
       } else {
         CurrentRequest = std::move(Requests.front());
         Requests.pop_front();
       }
     } // unlock Mutex
 
+    // Inform tracing that the request was dequeued.
+    CurrentRequest->QueueCtx.reset();
+
     // It is safe to perform reads to CurrentRequest without holding the lock as
     // only writer is also this thread.
     {