[Lldb-commits] [lldb] 9f9464e - [trace][intel pt] Measure the time it takes to decode a thread in per-cpu mode

Walter Erquinigo via lldb-commits lldb-commits at lists.llvm.org
Wed Jul 13 11:08:22 PDT 2022


Author: Peicong Wu
Date: 2022-07-13T11:08:14-07:00
New Revision: 9f9464e02adaeb0a56211db35e8d22929ef3191f

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

LOG: [trace][intel pt] Measure the time it takes to decode a thread in per-cpu mode

This metric was missing. We were only measuring in per-thread mode, and
this completes the work.

For a sample trace I have, the `dump info` command shows

```
Timing for this thread:
    Decoding instructions: 0.12s

```

I also improved a bit the TaskTime function so that callers don't need to
specify the template argument

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

Added: 
    

Modified: 
    lldb/source/Plugins/Trace/intel-pt/TaskTimer.h
    lldb/source/Plugins/Trace/intel-pt/ThreadDecoder.cpp
    lldb/source/Plugins/Trace/intel-pt/TraceIntelPT.cpp
    lldb/source/Plugins/Trace/intel-pt/TraceIntelPT.h
    lldb/source/Plugins/Trace/intel-pt/TraceIntelPTMultiCpuDecoder.cpp

Removed: 
    


################################################################################
diff  --git a/lldb/source/Plugins/Trace/intel-pt/TaskTimer.h b/lldb/source/Plugins/Trace/intel-pt/TaskTimer.h
index 92b563257437..2b85ed30334f 100644
--- a/lldb/source/Plugins/Trace/intel-pt/TaskTimer.h
+++ b/lldb/source/Plugins/Trace/intel-pt/TaskTimer.h
@@ -35,9 +35,9 @@ class ScopedTaskTimer {
   ///
   /// \return
   ///     The return value of the task.
-  template <class R> R TimeTask(llvm::StringRef name, std::function<R()> task) {
+  template <typename C> auto TimeTask(llvm::StringRef name, C task) {
     auto start = std::chrono::steady_clock::now();
-    R result = task();
+    auto result = task();
     auto end = std::chrono::steady_clock::now();
     std::chrono::milliseconds duration =
         std::chrono::duration_cast<std::chrono::milliseconds>(end - start);

diff  --git a/lldb/source/Plugins/Trace/intel-pt/ThreadDecoder.cpp b/lldb/source/Plugins/Trace/intel-pt/ThreadDecoder.cpp
index 8b90afb219af..d3ac61f7e658 100644
--- a/lldb/source/Plugins/Trace/intel-pt/ThreadDecoder.cpp
+++ b/lldb/source/Plugins/Trace/intel-pt/ThreadDecoder.cpp
@@ -35,9 +35,8 @@ Expected<DecodedThreadSP> ThreadDecoder::Decode() {
 }
 
 llvm::Expected<DecodedThreadSP> ThreadDecoder::DoDecode() {
-  return m_trace.GetTimer()
-      .ForThread(m_thread_sp->GetID())
-      .TimeTask<Expected<DecodedThreadSP>>(
+  return m_trace.GetThreadTimer(m_thread_sp->GetID())
+      .TimeTask(
           "Decoding instructions", [&]() -> Expected<DecodedThreadSP> {
             DecodedThreadSP decoded_thread_sp =
                 std::make_shared<DecodedThread>(m_thread_sp);

diff  --git a/lldb/source/Plugins/Trace/intel-pt/TraceIntelPT.cpp b/lldb/source/Plugins/Trace/intel-pt/TraceIntelPT.cpp
index a5faae419780..55053805462d 100644
--- a/lldb/source/Plugins/Trace/intel-pt/TraceIntelPT.cpp
+++ b/lldb/source/Plugins/Trace/intel-pt/TraceIntelPT.cpp
@@ -199,10 +199,10 @@ void TraceIntelPT::DumpTraceInfo(Thread &thread, Stream &s, bool verbose) {
                               std::chrono::milliseconds duration) {
       s.Format("    {0}: {1:2}s\n", name, duration.count() / 1000.0);
     };
-    GetTimer().ForThread(tid).ForEachTimedTask(print_duration);
+    GetThreadTimer(tid).ForEachTimedTask(print_duration);
 
     s << "\n  Timing for global tasks:\n";
-    GetTimer().ForGlobal().ForEachTimedTask(print_duration);
+    GetGlobalTimer().ForEachTimedTask(print_duration);
   }
 
   // Instruction events stats
@@ -507,3 +507,11 @@ Error TraceIntelPT::OnThreadBufferRead(lldb::tid_t tid,
 }
 
 TaskTimer &TraceIntelPT::GetTimer() { return GetUpdatedStorage().task_timer; }
+
+ScopedTaskTimer &TraceIntelPT::GetThreadTimer(lldb::tid_t tid) {
+  return GetTimer().ForThread(tid);
+}
+
+ScopedTaskTimer &TraceIntelPT::GetGlobalTimer() {
+  return GetTimer().ForGlobal();
+}

diff  --git a/lldb/source/Plugins/Trace/intel-pt/TraceIntelPT.h b/lldb/source/Plugins/Trace/intel-pt/TraceIntelPT.h
index 09ecbe7da61a..af68539a072e 100644
--- a/lldb/source/Plugins/Trace/intel-pt/TraceIntelPT.h
+++ b/lldb/source/Plugins/Trace/intel-pt/TraceIntelPT.h
@@ -157,6 +157,14 @@ class TraceIntelPT : public Trace {
   ///     The timer object for this trace.
   TaskTimer &GetTimer();
 
+  /// \return
+  ///     The ScopedTaskTimer object for the given thread in this trace.
+  ScopedTaskTimer &GetThreadTimer(lldb::tid_t tid);
+
+  /// \return
+  ///     The global copedTaskTimer object for this trace.
+  ScopedTaskTimer &GetGlobalTimer();
+
   TraceIntelPTSP GetSharedPtr();
 
 private:

diff  --git a/lldb/source/Plugins/Trace/intel-pt/TraceIntelPTMultiCpuDecoder.cpp b/lldb/source/Plugins/Trace/intel-pt/TraceIntelPTMultiCpuDecoder.cpp
index d2dbc049672c..12fbe934a31b 100644
--- a/lldb/source/Plugins/Trace/intel-pt/TraceIntelPTMultiCpuDecoder.cpp
+++ b/lldb/source/Plugins/Trace/intel-pt/TraceIntelPTMultiCpuDecoder.cpp
@@ -39,30 +39,35 @@ Expected<DecodedThreadSP> TraceIntelPTMultiCpuDecoder::Decode(Thread &thread) {
   if (Error err = CorrelateContextSwitchesAndIntelPtTraces())
     return std::move(err);
 
-  auto it = m_decoded_threads.find(thread.GetID());
-  if (it != m_decoded_threads.end())
-    return it->second;
-
-  DecodedThreadSP decoded_thread_sp =
-      std::make_shared<DecodedThread>(thread.shared_from_this());
-
   TraceIntelPTSP trace_sp = GetTrace();
 
-  Error err = trace_sp->OnAllCpusBinaryDataRead(
-      IntelPTDataKinds::kIptTrace,
-      [&](const DenseMap<cpu_id_t, ArrayRef<uint8_t>> &buffers) -> Error {
-        auto it = m_continuous_executions_per_thread->find(thread.GetID());
-        if (it != m_continuous_executions_per_thread->end())
-          return DecodeSystemWideTraceForThread(*decoded_thread_sp, *trace_sp,
-                                                buffers, it->second);
-
-        return Error::success();
+  return trace_sp
+      ->GetThreadTimer(thread.GetID())
+      .TimeTask("Decoding instructions", [&]() -> Expected<DecodedThreadSP> {
+        auto it = m_decoded_threads.find(thread.GetID());
+        if (it != m_decoded_threads.end())
+          return it->second;
+
+        DecodedThreadSP decoded_thread_sp =
+            std::make_shared<DecodedThread>(thread.shared_from_this());
+
+        Error err = trace_sp->OnAllCpusBinaryDataRead(
+            IntelPTDataKinds::kIptTrace,
+            [&](const DenseMap<cpu_id_t, ArrayRef<uint8_t>> &buffers) -> Error {
+              auto it =
+                  m_continuous_executions_per_thread->find(thread.GetID());
+              if (it != m_continuous_executions_per_thread->end())
+                return DecodeSystemWideTraceForThread(
+                    *decoded_thread_sp, *trace_sp, buffers, it->second);
+
+              return Error::success();
+            });
+        if (err)
+          return std::move(err);
+
+        m_decoded_threads.try_emplace(thread.GetID(), decoded_thread_sp);
+        return decoded_thread_sp;
       });
-  if (err)
-    return std::move(err);
-
-  m_decoded_threads.try_emplace(thread.GetID(), decoded_thread_sp);
-  return decoded_thread_sp;
 }
 
 static Expected<std::vector<IntelPTThreadSubtrace>>
@@ -153,7 +158,7 @@ Error TraceIntelPTMultiCpuDecoder::CorrelateContextSwitchesAndIntelPtTraces() {
   if (m_continuous_executions_per_thread)
     return Error::success();
 
-  Error err = GetTrace()->GetTimer().ForGlobal().TimeTask<Error>(
+  Error err = GetTrace()->GetGlobalTimer().TimeTask(
       "Context switch and Intel PT traces correlation", [&]() -> Error {
         if (auto correlation = DoCorrelateContextSwitchesAndIntelPtTraces()) {
           m_continuous_executions_per_thread.emplace(std::move(*correlation));


        


More information about the lldb-commits mailing list