sammccall created this revision.
sammccall added a reviewer: ilya-biryukov.
Herald added subscribers: cfe-commits, ioeric, jkorous-apple, klimek.

This has a bit of a blast radius, but I think there's enough value in "forcing"
us to give names to these async tasks for debugging. Guessing about what
multithreaded code is doing is so unfun...

The "file" param attached to the tasks may seem to be redundant with the thread
names, but note that thread names are truncated to 15 chars on linux!
We'll be lucky to get the whole basename...


Repository:
  rCTE Clang Tools Extra

https://reviews.llvm.org/D43388

Files:
  clangd/ClangdServer.cpp
  clangd/TUScheduler.cpp
  clangd/TUScheduler.h
  clangd/Threading.cpp
  clangd/Threading.h
  clangd/Trace.cpp
  clangd/Trace.h
  unittests/clangd/TUSchedulerTests.cpp
  unittests/clangd/ThreadingTests.cpp

Index: unittests/clangd/ThreadingTests.cpp
===================================================================
--- unittests/clangd/ThreadingTests.cpp
+++ unittests/clangd/ThreadingTests.cpp
@@ -29,7 +29,7 @@
     AsyncTaskRunner Tasks;
     auto scheduleIncrements = [&]() {
       for (int TaskI = 0; TaskI < TasksCnt; ++TaskI) {
-        Tasks.runAsync([&Counter, &Mutex, IncrementsPerTask]() {
+        Tasks.runAsync("task", [&Counter, &Mutex, IncrementsPerTask]() {
           for (int Increment = 0; Increment < IncrementsPerTask; ++Increment) {
             std::lock_guard<std::mutex> Lock(Mutex);
             ++Counter;
Index: unittests/clangd/TUSchedulerTests.cpp
===================================================================
--- unittests/clangd/TUSchedulerTests.cpp
+++ unittests/clangd/TUSchedulerTests.cpp
@@ -54,31 +54,33 @@
 
   // Assert each operation for missing file is an error (even if it's available
   // in VFS).
-  S.runWithAST(Missing, [&](llvm::Expected<InputsAndAST> AST) {
+  S.runWithAST("", Missing, [&](llvm::Expected<InputsAndAST> AST) {
     ASSERT_FALSE(bool(AST));
     ignoreError(AST.takeError());
   });
-  S.runWithPreamble(Missing, [&](llvm::Expected<InputsAndPreamble> Preamble) {
-    ASSERT_FALSE(bool(Preamble));
-    ignoreError(Preamble.takeError());
-  });
+  S.runWithPreamble("", Missing,
+                    [&](llvm::Expected<InputsAndPreamble> Preamble) {
+                      ASSERT_FALSE(bool(Preamble));
+                      ignoreError(Preamble.takeError());
+                    });
   // remove() shouldn't crash on missing files.
   S.remove(Missing);
 
   // Assert there aren't any errors for added file.
-  S.runWithAST(
-      Added, [&](llvm::Expected<InputsAndAST> AST) { EXPECT_TRUE(bool(AST)); });
-  S.runWithPreamble(Added, [&](llvm::Expected<InputsAndPreamble> Preamble) {
+  S.runWithAST("", Added, [&](llvm::Expected<InputsAndAST> AST) {
+    EXPECT_TRUE(bool(AST));
+  });
+  S.runWithPreamble("", Added, [&](llvm::Expected<InputsAndPreamble> Preamble) {
     EXPECT_TRUE(bool(Preamble));
   });
   S.remove(Added);
 
   // Assert that all operations fail after removing the file.
-  S.runWithAST(Added, [&](llvm::Expected<InputsAndAST> AST) {
+  S.runWithAST("", Added, [&](llvm::Expected<InputsAndAST> AST) {
     ASSERT_FALSE(bool(AST));
     ignoreError(AST.takeError());
   });
-  S.runWithPreamble(Added, [&](llvm::Expected<InputsAndPreamble> Preamble) {
+  S.runWithPreamble("", Added, [&](llvm::Expected<InputsAndPreamble> Preamble) {
     ASSERT_FALSE(bool(Preamble));
     ignoreError(Preamble.takeError());
   });
@@ -143,24 +145,27 @@
 
         {
           WithContextValue WithNonce(NonceKey, ++Nonce);
-          S.runWithAST(File, [Inputs, Nonce, &Mut, &TotalASTReads](
-                                 llvm::Expected<InputsAndAST> AST) {
-            EXPECT_THAT(Context::current().get(NonceKey), Pointee(Nonce));
-
-            ASSERT_TRUE((bool)AST);
-            EXPECT_EQ(AST->Inputs.FS, Inputs.FS);
-            EXPECT_EQ(AST->Inputs.Contents, Inputs.Contents);
-
-            std::lock_guard<std::mutex> Lock(Mut);
-            ++TotalASTReads;
-          });
+          S.runWithAST("CheckAST", File,
+                       [Inputs, Nonce, &Mut,
+                        &TotalASTReads](llvm::Expected<InputsAndAST> AST) {
+                         EXPECT_THAT(Context::current().get(NonceKey),
+                                     Pointee(Nonce));
+
+                         ASSERT_TRUE((bool)AST);
+                         EXPECT_EQ(AST->Inputs.FS, Inputs.FS);
+                         EXPECT_EQ(AST->Inputs.Contents, Inputs.Contents);
+
+                         std::lock_guard<std::mutex> Lock(Mut);
+                         ++TotalASTReads;
+                       });
         }
 
         {
           WithContextValue WithNonce(NonceKey, ++Nonce);
           S.runWithPreamble(
-              File, [Inputs, Nonce, &Mut, &TotalPreambleReads](
-                        llvm::Expected<InputsAndPreamble> Preamble) {
+              "CheckPreamble", File,
+              [Inputs, Nonce, &Mut, &TotalPreambleReads](
+                  llvm::Expected<InputsAndPreamble> Preamble) {
                 EXPECT_THAT(Context::current().get(NonceKey), Pointee(Nonce));
 
                 ASSERT_TRUE((bool)Preamble);
Index: clangd/Trace.h
===================================================================
--- clangd/Trace.h
+++ clangd/Trace.h
@@ -82,7 +82,7 @@
 /// SomeJSONExpr is evaluated and copied only if actually needed.
 class Span {
 public:
-  Span(llvm::StringRef Name);
+  Span(llvm::Twine Name);
   ~Span();
 
   /// Mutable metadata, if this span is interested.
Index: clangd/Trace.cpp
===================================================================
--- clangd/Trace.cpp
+++ clangd/Trace.cpp
@@ -208,17 +208,19 @@
 }
 
 // Returned context owns Args.
-static Context makeSpanContext(llvm::StringRef Name, json::obj *Args) {
+static Context makeSpanContext(llvm::Twine Name, json::obj *Args) {
   if (!T)
     return Context::current().clone();
   WithContextValue WithArgs{std::unique_ptr<json::obj>(Args)};
-  return T->beginSpan(Name, Args);
+  return T->beginSpan(Name.isSingleStringRef() ? Name.getSingleStringRef()
+                                               : llvm::StringRef(Name.str()),
+                      Args);
 }
 
 // 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::StringRef Name)
+Span::Span(llvm::Twine Name)
     : Args(T ? new json::obj() : nullptr),
       RestoreCtx(makeSpanContext(Name, Args)) {}
 
Index: clangd/Threading.h
===================================================================
--- clangd/Threading.h
+++ clangd/Threading.h
@@ -12,6 +12,7 @@
 
 #include "Context.h"
 #include "Function.h"
+#include "llvm/ADT/Twine.h"
 #include <atomic>
 #include <cassert>
 #include <condition_variable>
@@ -81,7 +82,8 @@
 
   void wait() const { (void) wait(llvm::None); }
   LLVM_NODISCARD bool wait(Deadline D) const;
-  void runAsync(UniqueFunction<void()> Action);
+  // The name is used for tracing and debugging (e.g. to name a spawned thread).
+  void runAsync(llvm::Twine Name, UniqueFunction<void()> Action);
 
 private:
   mutable std::mutex Mutex;
Index: clangd/Threading.cpp
===================================================================
--- clangd/Threading.cpp
+++ clangd/Threading.cpp
@@ -34,7 +34,8 @@
                       [&] { return InFlightTasks == 0; });
 }
 
-void AsyncTaskRunner::runAsync(UniqueFunction<void()> Action) {
+void AsyncTaskRunner::runAsync(llvm::Twine Name,
+                               UniqueFunction<void()> Action) {
   {
     std::lock_guard<std::mutex> Lock(Mutex);
     ++InFlightTasks;
@@ -51,13 +52,14 @@
   });
 
   std::thread(
-      [](decltype(Action) Action, decltype(CleanupTask)) {
+      [](std::string Name, decltype(Action) Action, decltype(CleanupTask)) {
+        llvm::set_thread_name(Name);
         Action();
         // Make sure function stored by Action is destroyed before CleanupTask
         // is run.
         Action = nullptr;
       },
-      std::move(Action), std::move(CleanupTask))
+      Name.str(), std::move(Action), std::move(CleanupTask))
       .detach();
 }
 
Index: clangd/TUScheduler.h
===================================================================
--- clangd/TUScheduler.h
+++ clangd/TUScheduler.h
@@ -37,7 +37,7 @@
 /// TUScheduler is not thread-safe, only one thread should be providing updates
 /// and scheduling tasks.
 /// Callbacks are run on a threadpool and it's appropriate to do slow work in
-/// them.
+/// them. Each task has a name, used for tracing (should be UpperCamelCase).
 class TUScheduler {
 public:
   TUScheduler(unsigned AsyncThreadsCount, bool StorePreamblesInMemory,
@@ -65,16 +65,16 @@
   /// \p Action is executed.
   /// If an error occurs during processing, it is forwarded to the \p Action
   /// callback.
-  void runWithAST(PathRef File,
+  void runWithAST(llvm::StringRef Name, PathRef File,
                   UniqueFunction<void(llvm::Expected<InputsAndAST>)> Action);
 
   /// Schedule an async read of the Preamble. Preamble passed to \p Action may
   /// be built for any version of the file, callers must not rely on it being
   /// consistent with the current version of the file.
   /// If an error occurs during processing, it is forwarded to the \p Action
   /// callback.
   void runWithPreamble(
-      PathRef File,
+      llvm::StringRef Name, PathRef File,
       UniqueFunction<void(llvm::Expected<InputsAndPreamble>)> Action);
 
   /// Wait until there are no scheduled or running tasks.
Index: clangd/TUScheduler.cpp
===================================================================
--- clangd/TUScheduler.cpp
+++ clangd/TUScheduler.cpp
@@ -44,8 +44,10 @@
 
 #include "TUScheduler.h"
 #include "Logger.h"
+#include "Trace.h"
 #include "clang/Frontend/PCHContainerOperations.h"
 #include "llvm/Support/Errc.h"
+#include "llvm/Support/Path.h"
 #include <memory>
 #include <queue>
 #include <thread>
@@ -67,22 +69,24 @@
 /// worker.
 class ASTWorker {
   friend class ASTWorkerHandle;
-  ASTWorker(Semaphore &Barrier, CppFile AST, bool RunSync);
+  ASTWorker(llvm::StringRef File, Semaphore &Barrier, CppFile AST,
+            bool RunSync);
 
 public:
   /// Create a new ASTWorker and return a handle to it.
   /// The processing thread is spawned using \p Tasks. However, when \p Tasks
   /// is null, all requests will be processed on the calling thread
   /// synchronously instead. \p Barrier is acquired when processing each
   /// request, it is be used to limit the number of actively running threads.
-  static ASTWorkerHandle Create(AsyncTaskRunner *Tasks, Semaphore &Barrier,
-                                CppFile AST);
+  static ASTWorkerHandle Create(llvm::StringRef File, AsyncTaskRunner *Tasks,
+                                Semaphore &Barrier, CppFile AST);
   ~ASTWorker();
 
   void update(ParseInputs Inputs,
               UniqueFunction<void(llvm::Optional<std::vector<DiagWithFixIts>>)>
                   OnUpdated);
-  void runWithAST(UniqueFunction<void(llvm::Expected<InputsAndAST>)> Action);
+  void runWithAST(llvm::StringRef Name,
+                  UniqueFunction<void(llvm::Expected<InputsAndAST>)> Action);
   bool blockUntilIdle(Deadline Timeout) const;
 
   std::shared_ptr<const PreambleData> getPossiblyStalePreamble() const;
@@ -96,11 +100,16 @@
   /// Signal that run() should finish processing pending requests and exit.
   void stop();
   /// Adds a new task to the end of the request queue.
-  void startTask(UniqueFunction<void()> Task, bool isUpdate,
-                 llvm::Optional<CancellationFlag> CF);
+  void startTask(llvm::StringRef Name, UniqueFunction<void()> Task,
+                 bool isUpdate, llvm::Optional<CancellationFlag> CF);
 
-  using RequestWithCtx = std::pair<UniqueFunction<void()>, Context>;
+  struct Request {
+    UniqueFunction<void()> Action;
+    std::string Name;
+    Context Ctx;
+  };
 
+  std::string File;
   const bool RunSync;
   Semaphore &Barrier;
   // AST and FileInputs are only accessed on the processing thread from run().
@@ -114,7 +123,7 @@
   std::size_t LastASTSize; /* GUARDED_BY(Mutex) */
   // Set to true to signal run() to finish processing.
   bool Done;                           /* GUARDED_BY(Mutex) */
-  std::queue<RequestWithCtx> Requests; /* GUARDED_BY(Mutex) */
+  std::queue<Request> Requests;        /* GUARDED_BY(Mutex) */
   // Only set when last request is an update. This allows us to cancel an update
   // that was never read, if a subsequent update comes in.
   llvm::Optional<CancellationFlag> LastUpdateCF; /* GUARDED_BY(Mutex) */
@@ -163,18 +172,21 @@
   std::shared_ptr<ASTWorker> Worker;
 };
 
-ASTWorkerHandle ASTWorker::Create(AsyncTaskRunner *Tasks, Semaphore &Barrier,
-                                  CppFile AST) {
+ASTWorkerHandle ASTWorker::Create(llvm::StringRef File, AsyncTaskRunner *Tasks,
+                                  Semaphore &Barrier, CppFile AST) {
   std::shared_ptr<ASTWorker> Worker(
-      new ASTWorker(Barrier, std::move(AST), /*RunSync=*/!Tasks));
+      new ASTWorker(File, Barrier, std::move(AST), /*RunSync=*/!Tasks));
   if (Tasks)
-    Tasks->runAsync([Worker]() { Worker->run(); });
+    Tasks->runAsync("worker:" + llvm::sys::path::filename(File),
+                    [Worker]() { Worker->run(); });
 
   return ASTWorkerHandle(std::move(Worker));
 }
 
-ASTWorker::ASTWorker(Semaphore &Barrier, CppFile AST, bool RunSync)
-    : RunSync(RunSync), Barrier(Barrier), AST(std::move(AST)), Done(false) {
+ASTWorker::ASTWorker(llvm::StringRef File, Semaphore &Barrier, CppFile AST,
+                     bool RunSync)
+    : File(File), RunSync(RunSync), Barrier(Barrier), AST(std::move(AST)),
+      Done(false) {
   if (RunSync)
     return;
 }
@@ -212,11 +224,12 @@
   };
 
   CancellationFlag UpdateCF;
-  startTask(BindWithForward(Task, UpdateCF, std::move(OnUpdated)),
+  startTask("Update", BindWithForward(Task, UpdateCF, std::move(OnUpdated)),
             /*isUpdate=*/true, UpdateCF);
 }
 
 void ASTWorker::runWithAST(
+    llvm::StringRef Name,
     UniqueFunction<void(llvm::Expected<InputsAndAST>)> Action) {
   auto Task = [=](decltype(Action) Action) {
     ParsedAST *ActualAST = AST.getAST();
@@ -233,8 +246,8 @@
     LastASTSize = ActualAST->getUsedBytes();
   };
 
-  startTask(BindWithForward(Task, std::move(Action)), /*isUpdate=*/false,
-            llvm::None);
+  startTask(Name, BindWithForward(Task, std::move(Action)),
+            /*isUpdate=*/false, llvm::None);
 }
 
 std::shared_ptr<const PreambleData>
@@ -257,13 +270,14 @@
   RequestsCV.notify_all();
 }
 
-void ASTWorker::startTask(UniqueFunction<void()> Task, bool isUpdate,
-                          llvm::Optional<CancellationFlag> CF) {
+void ASTWorker::startTask(llvm::StringRef Name, UniqueFunction<void()> Task,
+                          bool isUpdate, llvm::Optional<CancellationFlag> CF) {
   assert(isUpdate == CF.hasValue() &&
          "Only updates are expected to pass CancellationFlag");
 
   if (RunSync) {
     assert(!Done && "running a task after stop()");
+    trace::Span Tracer(Name + ":" + llvm::sys::path::filename(File));
     Task();
     return;
   }
@@ -281,14 +295,14 @@
     } else {
       LastUpdateCF = llvm::None;
     }
-    Requests.emplace(std::move(Task), Context::current().clone());
+    Requests.push({std::move(Task), Name, Context::current().clone()});
   } // unlock Mutex.
   RequestsCV.notify_all();
 }
 
 void ASTWorker::run() {
   while (true) {
-    RequestWithCtx Req;
+    Request Req;
     {
       std::unique_lock<std::mutex> Lock(Mutex);
       RequestsCV.wait(Lock, [&]() { return Done || !Requests.empty(); });
@@ -303,9 +317,12 @@
       // Leave it on the queue for now, so waiters don't see an empty queue.
     } // unlock Mutex
 
-    std::lock_guard<Semaphore> BarrierLock(Barrier);
-    WithContext Guard(std::move(Req.second));
-    Req.first();
+    {
+      std::lock_guard<Semaphore> BarrierLock(Barrier);
+      WithContext Guard(std::move(Req.Ctx));
+      trace::Span Tracer(Req.Name);
+      Req.Action();
+    }
 
     {
       std::lock_guard<std::mutex> Lock(Mutex);
@@ -379,7 +396,7 @@
   if (!FD) {
     // Create a new worker to process the AST-related tasks.
     ASTWorkerHandle Worker = ASTWorker::Create(
-        WorkerThreads ? WorkerThreads.getPointer() : nullptr, Barrier,
+        File, WorkerThreads ? WorkerThreads.getPointer() : nullptr, Barrier,
         CppFile(File, StorePreamblesInMemory, PCHOps, ASTCallback));
     FD = std::unique_ptr<FileData>(new FileData{Inputs, std::move(Worker)});
   } else {
@@ -396,20 +413,21 @@
 }
 
 void TUScheduler::runWithAST(
-    PathRef File, UniqueFunction<void(llvm::Expected<InputsAndAST>)> Action) {
+    llvm::StringRef Name, PathRef File,
+    UniqueFunction<void(llvm::Expected<InputsAndAST>)> Action) {
   auto It = Files.find(File);
   if (It == Files.end()) {
     Action(llvm::make_error<llvm::StringError>(
         "trying to get AST for non-added document",
         llvm::errc::invalid_argument));
     return;
   }
 
-  It->second->Worker->runWithAST(std::move(Action));
+  It->second->Worker->runWithAST(Name, std::move(Action));
 }
 
 void TUScheduler::runWithPreamble(
-    PathRef File,
+    llvm::StringRef Name, PathRef File,
     UniqueFunction<void(llvm::Expected<InputsAndPreamble>)> Action) {
   auto It = Files.find(File);
   if (It == Files.end()) {
@@ -420,25 +438,31 @@
   }
 
   if (!PreambleTasks) {
+    trace::Span Tracer(Name);
+    SPAN_ATTACH(Tracer, "file", File);
     std::shared_ptr<const PreambleData> Preamble =
         It->second->Worker->getPossiblyStalePreamble();
     Action(InputsAndPreamble{It->second->Inputs, Preamble.get()});
     return;
   }
 
   ParseInputs InputsCopy = It->second->Inputs;
   std::shared_ptr<const ASTWorker> Worker = It->second->Worker.lock();
-  auto Task = [InputsCopy, Worker, this](Context Ctx,
+  auto Task = [InputsCopy, Worker, this](std::string Name, Context Ctx,
                                          decltype(Action) Action) mutable {
     std::lock_guard<Semaphore> BarrierLock(Barrier);
     WithContext Guard(std::move(Ctx));
+    trace::Span Tracer(Name);
+    SPAN_ATTACH(Tracer, "file", File);
     std::shared_ptr<const PreambleData> Preamble =
         Worker->getPossiblyStalePreamble();
     Action(InputsAndPreamble{InputsCopy, Preamble.get()});
   };
 
-  PreambleTasks->runAsync(
-      BindWithForward(Task, Context::current().clone(), std::move(Action)));
+  PreambleTasks->runAsync("task:" + llvm::sys::path::filename(File),
+                          BindWithForward(Task, std::string(Name),
+                                          Context::current().clone(),
+                                          std::move(Action)));
 }
 
 std::vector<std::pair<Path, std::size_t>>
Index: clangd/ClangdServer.cpp
===================================================================
--- clangd/ClangdServer.cpp
+++ clangd/ClangdServer.cpp
@@ -179,9 +179,10 @@
     Callback(make_tagged(std::move(Result), std::move(TaggedFS.Tag)));
   };
 
-  WorkScheduler.runWithPreamble(File, BindWithForward(Task, std::move(Contents),
-                                                      File.str(),
-                                                      std::move(Callback)));
+  WorkScheduler.runWithPreamble("CodeComplete", File,
+                                BindWithForward(Task, std::move(Contents),
+                                                File.str(),
+                                                std::move(Callback)));
 }
 
 void ClangdServer::signatureHelp(
@@ -222,7 +223,8 @@
   };
 
   WorkScheduler.runWithPreamble(
-      File, BindWithForward(Action, File.str(), std::move(Callback)));
+      "SignatureHelp", File,
+      BindWithForward(Action, File.str(), std::move(Callback)));
 }
 
 llvm::Expected<tooling::Replacements>
@@ -307,7 +309,7 @@
   };
 
   WorkScheduler.runWithAST(
-      File,
+      "Rename", File,
       BindWithForward(Action, File.str(), NewName.str(), std::move(Callback)));
 }
 
@@ -376,7 +378,8 @@
     Callback(Result);
   };
 
-  WorkScheduler.runWithAST(File, BindWithForward(Action, std::move(Callback)));
+  WorkScheduler.runWithAST("DumpAST", File,
+                           BindWithForward(Action, std::move(Callback)));
 }
 
 void ClangdServer::findDefinitions(
@@ -392,7 +395,8 @@
     Callback(make_tagged(std::move(Result), TaggedFS.Tag));
   };
 
-  WorkScheduler.runWithAST(File, BindWithForward(Action, std::move(Callback)));
+  WorkScheduler.runWithAST("Definitions", File,
+                           BindWithForward(Action, std::move(Callback)));
 }
 
 llvm::Optional<Path> ClangdServer::switchSourceHeader(PathRef Path) {
@@ -488,7 +492,8 @@
     Callback(make_tagged(std::move(Result), TaggedFS.Tag));
   };
 
-  WorkScheduler.runWithAST(File, BindWithForward(Action, std::move(Callback)));
+  WorkScheduler.runWithAST("Highlights", File,
+                           BindWithForward(Action, std::move(Callback)));
 }
 
 void ClangdServer::scheduleReparseAndDiags(
_______________________________________________
cfe-commits mailing list
cfe-commits@lists.llvm.org
http://lists.llvm.org/cgi-bin/mailman/listinfo/cfe-commits

Reply via email to