diff --git a/clang-tools-extra/clangd/TUScheduler.cpp b/clang-tools-extra/clangd/TUScheduler.cpp --- a/clang-tools-extra/clangd/TUScheduler.cpp +++ b/clang-tools-extra/clangd/TUScheduler.cpp @@ -465,6 +465,7 @@ std::string Name; steady_clock::time_point AddTime; Context Ctx; + llvm::Optional QueueCtx; llvm::Optional Update; TUScheduler::ASTActionInvalidation InvalidationPolicy; Canceler Invalidate; @@ -507,7 +508,7 @@ /// None means no builds yet, null means there was an error while building. /// Only written by ASTWorker's thread. llvm::Optional> LatestPreamble; - std::queue PreambleRequests; /* GUARDED_BY(Mutex) */ + std::deque PreambleRequests; /* GUARDED_BY(Mutex) */ /// Signaled whenever LatestPreamble changes state or there's a new /// PreambleRequest. mutable std::condition_variable PreambleCV; @@ -826,9 +827,10 @@ } { std::lock_guard 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 @@ std::tie(Ctx, Invalidate) = cancelableTask( /*Reason=*/static_cast(ErrorCode::ContentModified)); } + // Trace the time the request spends in the queue, and the requests that + // it's going to wait for. + llvm::Optional 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 @@ // 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. {