[trace][intel pt] Create a CPU change event and expose it in the dumper

Thanks to fredzhou@fb.com for coming up with this feature.

When tracing in per-cpu mode, we have information of in which cpu we are execution each instruction, which comes from the context switch trace. This diff makes this information available as a `cpu changed event`, which an additional accessor in the cursor `GetCPU()`. As cpu changes are very infrequent, any consumer should listen to cpu change events instead of querying the actual cpu of a trace item. Once a cpu change event is seen, the consumer can invoke GetCPU() to get that information. Also, it's possible to invoke GetCPU() on an arbitrary instruction item, which will return the last cpu seen. However, this call is O(logn) and should be used sparingly.

Manually tested with a sample program that starts on cpu 52, then goes to 18, and then goes back to 52.

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

diff --git a/lldb/include/lldb/Target/TraceCursor.h b/lldb/include/lldb/Target/TraceCursor.h
index a4cf6433c19a4775b093702d217a0e028391121c..f6337e3d3d3fd669f8760365bc025a1239092fc2 100644 (file)
--- a/lldb/include/lldb/Target/TraceCursor.h
+++ b/lldb/include/lldb/Target/TraceCursor.h
@@ -266,6 +266,16 @@ public:
   ///    The value of the counter or \b llvm::None if not available.
   virtual llvm::Optional<uint64_t>
   GetCounter(lldb::TraceCounter counter_type) const = 0;
+
+  /// Get the CPU associated with the current trace item.
+  ///
+  /// This call might not be O(1), so it's suggested to invoke this method
+  /// whenever a cpu change event is fired.
+  ///
+  /// \return
+  ///    The requested CPU id, or \a llvm::None if this information is
+  ///    not available for the current item.
+  virtual llvm::Optional<lldb::cpu_id_t> GetCPU() const = 0;
   /// \}
 
 protected:

diff --git a/lldb/include/lldb/Target/TraceDumper.h b/lldb/include/lldb/Target/TraceDumper.h
index a5b983b4e653e1965923aaacb876127b37fb1909..bbc1a55873d7e110b7d5e57e68937641206ee678 100644 (file)
--- a/lldb/include/lldb/Target/TraceDumper.h
+++ b/lldb/include/lldb/Target/TraceDumper.h
@@ -66,6 +66,7 @@ public:
     llvm::Optional<lldb::TraceEvent> event;
     llvm::Optional<SymbolInfo> symbol_info;
     llvm::Optional<SymbolInfo> prev_symbol_info;
+    llvm::Optional<lldb::cpu_id_t> cpu_id;
   };
 
   /// Interface used to abstract away the format in which the instruction

diff --git a/lldb/include/lldb/lldb-enumerations.h b/lldb/include/lldb/lldb-enumerations.h
index 3c03857c5498a57983190a8356c759d4c7eb8254..ad03f7e430567e00acaa7e8842b659f5dd40aaa3 100644 (file)
--- a/lldb/include/lldb/lldb-enumerations.h
+++ b/lldb/include/lldb/lldb-enumerations.h
@@ -1163,12 +1163,15 @@ enum TraceCounter {
   eTraceCounterTSC = 0,
 };
 
-// Events that might happen during a trace session.
+/// Events that might happen during a trace session.
 enum TraceEvent {
-  // Tracing was disabled for some time due to a software trigger
+  /// Tracing was disabled for some time due to a software trigger
   eTraceEventDisabledSW,
-  // Tracing was disable for some time due to a hardware trigger
+  /// Tracing was disable for some time due to a hardware trigger
   eTraceEventDisabledHW,
+  /// Event due to CPU change for a thread. This event is also fired when
+  /// suddenly it's not possible to identify the cpu of a given thread.
+  eTraceEventCPUChanged,
 };
 
 // Enum used to identify which kind of item a \a TraceCursor is pointing at

diff --git a/lldb/source/Plugins/Trace/intel-pt/DecodedThread.cpp b/lldb/source/Plugins/Trace/intel-pt/DecodedThread.cpp
index 578828ff1633f9075704831c5947104cfc6bc21f..0859c5a20b7e28b82fd3781b1cea706069aee125 100644 (file)
--- a/lldb/source/Plugins/Trace/intel-pt/DecodedThread.cpp
+++ b/lldb/source/Plugins/Trace/intel-pt/DecodedThread.cpp
@@ -63,11 +63,28 @@ DecodedThread::CreateNewTraceItem(lldb::TraceItemKind kind) {
 
 void DecodedThread::NotifyTsc(uint64_t tsc) {
   if (!m_last_tsc || *m_last_tsc != tsc) {
-    m_instruction_timestamps.emplace(m_item_kinds.size(), tsc);
+    m_timestamps.emplace(m_item_kinds.size(), tsc);
     m_last_tsc = tsc;
   }
 }
 
+void DecodedThread::NotifyCPU(lldb::cpu_id_t cpu_id) {
+  if (!m_last_cpu || *m_last_cpu != cpu_id) {
+    m_cpus.emplace(m_item_kinds.size(), cpu_id);
+    m_last_cpu = cpu_id;
+    AppendEvent(lldb::eTraceEventCPUChanged);
+  }
+}
+
+Optional<lldb::cpu_id_t>
+DecodedThread::GetCPUByIndex(uint64_t insn_index) const {
+  // Could possibly optimize the search
+  auto it = m_cpus.upper_bound(insn_index);
+  if (it == m_cpus.begin())
+    return None;
+  return prev(it)->second;
+}
+
 void DecodedThread::AppendEvent(lldb::TraceEvent event) {
   CreateNewTraceItem(lldb::eTraceItemKindEvent).event = event;
   m_events_stats.RecordEvent(event);
@@ -136,8 +153,8 @@ Optional<DecodedThread::TscRange> DecodedThread::CalculateTscRange(
       return candidate_range;
   }
   // Now we do a more expensive lookup
-  auto it = m_instruction_timestamps.upper_bound(insn_index);
-  if (it == m_instruction_timestamps.begin())
+  auto it = m_timestamps.upper_bound(insn_index);
+  if (it == m_timestamps.begin())
     return None;
 
   return TscRange(--it, *this);
@@ -160,7 +177,8 @@ lldb::TraceCursorUP DecodedThread::CreateNewCursor() {
 size_t DecodedThread::CalculateApproximateMemoryUsage() const {
   return sizeof(TraceItemStorage) * m_item_data.size() +
          sizeof(uint8_t) * m_item_kinds.size() +
-         (sizeof(size_t) + sizeof(uint64_t)) * m_instruction_timestamps.size();
+         (sizeof(size_t) + sizeof(uint64_t)) * m_timestamps.size() +
+         (sizeof(size_t) + sizeof(lldb::cpu_id_t)) * m_cpus.size();
 }
 
 DecodedThread::TscRange::TscRange(std::map<size_t, uint64_t>::const_iterator it,
@@ -168,7 +186,7 @@ DecodedThread::TscRange::TscRange(std::map<size_t, uint64_t>::const_iterator it,
     : m_it(it), m_decoded_thread(&decoded_thread) {
   auto next_it = m_it;
   ++next_it;
-  m_end_index = (next_it == m_decoded_thread->m_instruction_timestamps.end())
+  m_end_index = (next_it == m_decoded_thread->m_timestamps.end())
                     ? std::numeric_limits<uint64_t>::max()
                     : next_it->first - 1;
 }
@@ -191,13 +209,13 @@ bool DecodedThread::TscRange::InRange(size_t insn_index) const {
 Optional<DecodedThread::TscRange> DecodedThread::TscRange::Next() const {
   auto next_it = m_it;
   ++next_it;
-  if (next_it == m_decoded_thread->m_instruction_timestamps.end())
+  if (next_it == m_decoded_thread->m_timestamps.end())
     return None;
   return TscRange(next_it, *m_decoded_thread);
 }
 
 Optional<DecodedThread::TscRange> DecodedThread::TscRange::Prev() const {
-  if (m_it == m_decoded_thread->m_instruction_timestamps.begin())
+  if (m_it == m_decoded_thread->m_timestamps.begin())
     return None;
   auto prev_it = m_it;
   --prev_it;

diff --git a/lldb/source/Plugins/Trace/intel-pt/DecodedThread.h b/lldb/source/Plugins/Trace/intel-pt/DecodedThread.h
index b17e927fafe4b7d10d94eacbd667d0022cf2ee8b..bd1a90aaf250e2597884505e1876c88eefcaa0e3 100644 (file)
--- a/lldb/source/Plugins/Trace/intel-pt/DecodedThread.h
+++ b/lldb/source/Plugins/Trace/intel-pt/DecodedThread.h
@@ -168,6 +168,15 @@ public:
   ///   The underlying event type for the given trace item index.
   lldb::TraceEvent GetEventByIndex(int item_index) const;
 
+  /// Get the most recent CPU id before or at the given trace item index.
+  ///
+  /// \param[in] item_index
+  ///   The trace item index to compare with.
+  ///
+  /// \return
+  ///   The requested cpu id, or \a llvm::None if not available.
+  llvm::Optional<lldb::cpu_id_t> GetCPUByIndex(uint64_t item_index) const;
+
   /// \return
   ///     The load address of the instruction at the given index.
   lldb::addr_t GetInstructionLoadAddress(size_t item_index) const;
@@ -204,8 +213,13 @@ public:
   lldb::ThreadSP GetThread();
 
   /// Notify this object that a new tsc has been seen.
+  /// If this a new TSC, an event will be created.
   void NotifyTsc(uint64_t tsc);
 
+  /// Notify this object that a CPU has been seen.
+  /// If this a new CPU, an event will be created.
+  void NotifyCPU(lldb::cpu_id_t cpu_id);
+
   /// Append a decoding error.
   void AppendError(const IntelPTError &error);
 
@@ -254,10 +268,17 @@ private:
   /// are sporadic and we can think of them as ranges. If TSCs are present in
   /// the trace, all instructions will have an associated TSC, including the
   /// first one. Otherwise, this map will be empty.
-  std::map<uint64_t, uint64_t> m_instruction_timestamps;
+  std::map<uint64_t, uint64_t> m_timestamps;
   /// This is the chronologically last TSC that has been added.
   llvm::Optional<uint64_t> m_last_tsc = llvm::None;
 
+  // The cpu information is stored as a map. It maps `instruction index -> CPU`
+  // A CPU is associated with the next instructions that follow until the next
+  // cpu is seen.
+  std::map<uint64_t, lldb::cpu_id_t> m_cpus;
+  /// This is the chronologically last CPU ID.
+  llvm::Optional<uint64_t> m_last_cpu = llvm::None;
+
   /// Statistics of all tracing events.
   EventsStats m_events_stats;
   /// Statistics of libipt errors when decoding TSCs.

diff --git a/lldb/source/Plugins/Trace/intel-pt/LibiptDecoder.cpp b/lldb/source/Plugins/Trace/intel-pt/LibiptDecoder.cpp
index dd34467e38b578bb50e2a2a6ee83bd7e054cc14b..a98337a4e0584de8b2b81e1d7b67291a8ee422f9 100644 (file)
--- a/lldb/source/Plugins/Trace/intel-pt/LibiptDecoder.cpp
+++ b/lldb/source/Plugins/Trace/intel-pt/LibiptDecoder.cpp
@@ -285,6 +285,8 @@ Error lldb_private::trace_intel_pt::DecodeSystemWideTraceForThread(
   for (size_t i = 0; i < executions.size(); i++) {
     const IntelPTThreadContinousExecution &execution = executions[i];
 
+    decoded_thread.NotifyCPU(execution.thread_execution.cpu_id);
+
     auto variant = execution.thread_execution.variant;
     // If we haven't seen a PSB yet, then it's fine not to show errors
     if (has_seen_psbs) {

diff --git a/lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.cpp b/lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.cpp
index da91ba7c13d896f712093cd8effd953e5dcaa247..185c02b6bcd9e17f3a3fd0d6d44c3a70b1a61208 100644 (file)
--- a/lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.cpp
+++ b/lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.cpp
@@ -84,6 +84,10 @@ TraceCursorIntelPT::GetCounter(lldb::TraceCounter counter_type) const {
   }
 }
 
+Optional<lldb::cpu_id_t> TraceCursorIntelPT::GetCPU() const {
+  return m_decoded_thread_sp->GetCPUByIndex(m_pos);
+}
+
 lldb::TraceEvent TraceCursorIntelPT::GetEventType() const {
   return m_decoded_thread_sp->GetEventByIndex(m_pos);
 }

diff --git a/lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.h b/lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.h
index c90431de3bbc01abe9a3947182b80c3e509a946f..2e0f67e67dfc46ef386ac2c7e0d41077eeb1f058 100644 (file)
--- a/lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.h
+++ b/lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.h
@@ -34,6 +34,8 @@ public:
 
   lldb::TraceEvent GetEventType() const override;
 
+  llvm::Optional<lldb::cpu_id_t> GetCPU() const override;
+
   lldb::TraceItemKind GetItemKind() const override;
 
   bool GoToId(lldb::user_id_t id) override;

diff --git a/lldb/source/Target/TraceCursor.cpp b/lldb/source/Target/TraceCursor.cpp
index 1c3fabc4dec032b2c676b74eb2a6ee9a875636ff..b9f5070506033eba2e6e44f5190a6d4a1073cfe3 100644 (file)
--- a/lldb/source/Target/TraceCursor.cpp
+++ b/lldb/source/Target/TraceCursor.cpp
@@ -48,5 +48,7 @@ const char *TraceCursor::EventKindToString(lldb::TraceEvent event_kind) {
     return "hardware disabled tracing";
   case lldb::eTraceEventDisabledSW:
     return "software disabled tracing";
+  case lldb::eTraceEventCPUChanged:
+    return "CPU core changed";
   }
 }

diff --git a/lldb/source/Target/TraceDumper.cpp b/lldb/source/Target/TraceDumper.cpp
index 9e8b9d2b3df6fa19b6d1d992f8b35e68dc254e0b..e6d782558a2a75ddb9fdb1e7b39a3d315dd62944 100644 (file)
--- a/lldb/source/Target/TraceDumper.cpp
+++ b/lldb/source/Target/TraceDumper.cpp
@@ -129,18 +129,16 @@ public:
     m_s.Format("    {0}: ", item.id);
 
     if (m_options.show_tsc) {
-      m_s << "[tsc=";
-
-      if (item.tsc)
-        m_s.Format("{0}", *item.tsc);
-      else
-        m_s << "unavailable";
-
-      m_s << "] ";
+      m_s.Format("[tsc={0}] ",
+                 item.tsc ? std::to_string(*item.tsc) : "unavailable");
     }
 
     if (item.event) {
       m_s << "(event) " << TraceCursor::EventKindToString(*item.event);
+      if (*item.event == eTraceEventCPUChanged) {
+        m_s.Format(" [new CPU={0}]",
+                   item.cpu_id ? std::to_string(*item.cpu_id) : "unavailable");
+      }
     } else if (item.error) {
       m_s << "(error) " << *item.error;
     } else {
@@ -172,14 +170,16 @@ class OutputWriterJSON : public TraceDumper::OutputWriter {
   /* schema:
     error_message: string
     | {
+      "event": string,
       "id": decimal,
       "tsc"?: string decimal,
-      "event": string
+      "cpuId"? decimal,
     } | {
+      "error": string,
       "id": decimal,
       "tsc"?: string decimal,
-      "error": string,
     | {
+      "loadAddress": string decimal,
       "id": decimal,
       "tsc"?: string decimal,
       "module"?: string,
@@ -202,6 +202,11 @@ public:
 
   void DumpEvent(const TraceDumper::TraceItem &item) {
     m_j.attribute("event", TraceCursor::EventKindToString(*item.event));
+<<<<<<< HEAD
+=======
+    if (item.event == eTraceEventCPUChanged)
+      m_j.attribute("cpuId", item.cpu_id);
+>>>>>>> ccb96b741a18 ([trace][intel pt] Create a CPU change event and expose it in the dumper)
   }
 
   void DumpInstruction(const TraceDumper::TraceItem &item) {
@@ -211,12 +216,18 @@ public:
       m_j.attribute(
           "symbol",
           ToOptionalString(item.symbol_info->sc.GetFunctionName().AsCString()));
+<<<<<<< HEAD
 
       if (item.symbol_info->instruction) {
         m_j.attribute("mnemonic",
                       ToOptionalString(item.symbol_info->instruction->GetMnemonic(
                           &item.symbol_info->exe_ctx)));
       }
+=======
+      m_j.attribute("mnemonic",
+                    ToOptionalString(item.symbol_info->instruction->GetMnemonic(
+                        &item.symbol_info->exe_ctx)));
+>>>>>>> ccb96b741a18 ([trace][intel pt] Create a CPU change event and expose it in the dumper)
 
       if (IsLineEntryValid(item.symbol_info->sc.line_entry)) {
         m_j.attribute(
@@ -239,6 +250,7 @@ public:
 
       if (item.event) {
         DumpEvent(item);
+<<<<<<< HEAD
         return;
       }
 
@@ -249,6 +261,13 @@ public:
 
       // we know we are seeing an actual instruction
       DumpInstruction(item);
+=======
+      } else if (item.error) {
+        m_j.attribute("error", *item.error);
+      } else {
+        DumpInstruction(item);
+      }
+>>>>>>> ccb96b741a18 ([trace][intel pt] Create a CPU change event and expose it in the dumper)
     });
   }
 
@@ -369,6 +388,8 @@ Optional<lldb::user_id_t> TraceDumper::DumpInstructions(size_t count) {
       if (!m_options.show_events)
         continue;
       item.event = m_cursor_up->GetEventType();
+      if (*item.event == eTraceEventCPUChanged)
+        item.cpu_id = m_cursor_up->GetCPU();
     } else if (m_cursor_up->IsError()) {
       item.error = m_cursor_up->GetError();
     } else {

diff --git a/lldb/test/API/commands/trace/TestTraceEvents.py b/lldb/test/API/commands/trace/TestTraceEvents.py
index e72280ded686a4b6954ae473dc813c4f416dea96..83d6677a2ae2084a8749ebfad432de46aa355cab 100644 (file)
--- a/lldb/test/API/commands/trace/TestTraceEvents.py
+++ b/lldb/test/API/commands/trace/TestTraceEvents.py
@@ -6,6 +6,23 @@ from lldbsuite.test.decorators import *
 
 class TestTraceEvents(TraceIntelPTTestCaseBase):
 
+    @testSBAPIAndCommands
+    def testCPUEvents(self):
+      trace_description_file_path = os.path.join(self.getSourceDir(), "intelpt-multi-core-trace", "trace_missing_threads.json")
+      self.traceLoad(traceDescriptionFilePath=trace_description_file_path, substrs=["intel-pt"])
+
+      self.expect("thread trace dump instructions 3 -e --forward -c 5",
+        substrs=['''thread #3: tid = 3497496
+    0: (event) CPU core changed [new CPU=51]
+  m.out`foo() + 65 at multi_thread.cpp:12:21'''])
+
+      self.expect("thread trace dump instructions 3 -e --forward -c 5 -J",
+        substrs=['''{
+    "id": 0,
+    "event": "CPU core changed",
+    "cpuId": 51
+  }'''])
+
     @testSBAPIAndCommands
     def testPauseEvents(self):
       '''

diff --git a/lldb/test/API/commands/trace/TestTraceLoad.py b/lldb/test/API/commands/trace/TestTraceLoad.py
index 1699600c9e73a48643cab455134709bd07900257..adb38a4a9eb971b1b5872a49acd4ccd89ee8dc97 100644 (file)
--- a/lldb/test/API/commands/trace/TestTraceLoad.py
+++ b/lldb/test/API/commands/trace/TestTraceLoad.py
@@ -13,13 +13,80 @@ class TestTraceLoad(TraceIntelPTTestCaseBase):
         trace_description_file_path = os.path.join(src_dir, "intelpt-multi-core-trace", "trace.json")
         self.traceLoad(traceDescriptionFilePath=trace_description_file_path, substrs=["intel-pt"])
         self.expect("thread trace dump instructions 2 -t",
-          substrs=["19522: [tsc=40450075478109270] (error) expected tracing enabled event",
+          substrs=["19523: [tsc=40450075478109270] (error) expected tracing enabled event",
                    "m.out`foo() + 65 at multi_thread.cpp:12:21",
-                   "19520: [tsc=40450075477657246] 0x0000000000400ba7    jg     0x400bb3"])
+                   "19521: [tsc=40450075477657246] 0x0000000000400ba7    jg     0x400bb3"])
         self.expect("thread trace dump instructions 3 -t",
-          substrs=["67911: [tsc=40450075477799536] 0x0000000000400bd7    addl   $0x1, -0x4(%rbp)",
+          substrs=["67912: [tsc=40450075477799536] 0x0000000000400bd7    addl   $0x1, -0x4(%rbp)",
                    "m.out`bar() + 26 at multi_thread.cpp:20:6"])
 
+        self.expect("thread trace dump info --json",
+          substrs=['''{
+  "traceTechnology": "intel-pt",
+  "threadStats": {
+    "tid": 3497234,
+    "traceItemsCount": 0,
+    "memoryUsage": {
+      "totalInBytes": "0",
+      "avgPerItemInBytes": null
+    },
+    "timingInSeconds": {},
+    "events": {
+      "totalCount": 0,
+      "individualCounts": {}
+    },
+    "continuousExecutions": 0,
+    "PSBBlocks": 0,
+    "errorItems": {
+      "total": 0,
+      "individualErrors": {}
+    }
+  },
+  "globalStats": {
+    "timingInSeconds": {
+      "Context switch and Intel PT traces correlation": 0
+    },
+    "totalUnattributedPSBBlocks": 0,
+    "totalCountinuosExecutions": 153,
+    "totalPSBBlocks": 5,
+    "totalContinuousExecutions": 153
+  }
+}'''])
+
+        self.expect("thread trace dump info 2 --json",
+          substrs=['''{
+  "traceTechnology": "intel-pt",
+  "threadStats": {
+    "tid": 3497496,
+    "traceItemsCount": 19524,
+    "memoryUsage": {
+      "totalInBytes": "175760",
+      "avgPerItemInBytes": 9.00''', '''},
+    "timingInSeconds": {},
+    "events": {
+      "totalCount": 2,
+      "individualCounts": {
+        "software disabled tracing": 1,
+        "CPU core changed": 1
+      }
+    },
+    "continuousExecutions": 1,
+    "PSBBlocks": 1,
+    "errorItems": {
+      "total": 0,
+      "individualErrors": {}
+    }
+  },
+  "globalStats": {
+    "timingInSeconds": {
+      "Context switch and Intel PT traces correlation": 0''', '''},
+    "totalUnattributedPSBBlocks": 0,
+    "totalCountinuosExecutions": 153,
+    "totalPSBBlocks": 5,
+    "totalContinuousExecutions": 153
+  }
+}'''])
+
     @testSBAPIAndCommands
     def testLoadCompactMultiCoreTrace(self):
         src_dir = self.getSourceDir()
@@ -52,18 +119,17 @@ class TestTraceLoad(TraceIntelPTTestCaseBase):
         # We clean up for the next run of this test
         self.dbg.DeleteTarget(self.dbg.GetTargetAtIndex(0))
 
-
     @testSBAPIAndCommands
     def testLoadMultiCoreTraceWithStringNumbers(self):
         src_dir = self.getSourceDir()
         trace_description_file_path = os.path.join(src_dir, "intelpt-multi-core-trace", "trace_with_string_numbers.json")
         self.traceLoad(traceDescriptionFilePath=trace_description_file_path, substrs=["intel-pt"])
         self.expect("thread trace dump instructions 2 -t",
-          substrs=["19522: [tsc=40450075478109270] (error) expected tracing enabled event",
+          substrs=["19523: [tsc=40450075478109270] (error) expected tracing enabled event",
                    "m.out`foo() + 65 at multi_thread.cpp:12:21",
-                   "19520: [tsc=40450075477657246] 0x0000000000400ba7    jg     0x400bb3"])
+                   "19521: [tsc=40450075477657246] 0x0000000000400ba7    jg     0x400bb3"])
         self.expect("thread trace dump instructions 3 -t",
-          substrs=["67911: [tsc=40450075477799536] 0x0000000000400bd7    addl   $0x1, -0x4(%rbp)",
+          substrs=["67912: [tsc=40450075477799536] 0x0000000000400bd7    addl   $0x1, -0x4(%rbp)",
                    "m.out`bar() + 26 at multi_thread.cpp:20:6"])
 
     @testSBAPIAndCommands
@@ -72,11 +138,11 @@ class TestTraceLoad(TraceIntelPTTestCaseBase):
         trace_description_file_path = os.path.join(src_dir, "intelpt-multi-core-trace", "trace_missing_threads.json")
         self.traceLoad(traceDescriptionFilePath=trace_description_file_path, substrs=["intel-pt"])
         self.expect("thread trace dump instructions 3 -t",
-          substrs=["19522: [tsc=40450075478109270] (error) expected tracing enabled event",
+          substrs=["19523: [tsc=40450075478109270] (error) expected tracing enabled event",
                    "m.out`foo() + 65 at multi_thread.cpp:12:21",
-                   "19520: [tsc=40450075477657246] 0x0000000000400ba7    jg     0x400bb3"])
+                   "19521: [tsc=40450075477657246] 0x0000000000400ba7    jg     0x400bb3"])
         self.expect("thread trace dump instructions 2 -t",
-          substrs=["67911: [tsc=40450075477799536] 0x0000000000400bd7    addl   $0x1, -0x4(%rbp)",
+          substrs=["67912: [tsc=40450075477799536] 0x0000000000400bd7    addl   $0x1, -0x4(%rbp)",
                    "m.out`bar() + 26 at multi_thread.cpp:20:6"])
 
     @testSBAPIAndCommands