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

[wallace]

Summary

Thanks to [e-mail] 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.

[jj10306]

looks good overall, just a couple minor suggestions and questions

lldb/source/Plugins/Trace/intel-pt/LibiptDecoder.cpp

288

Does this mean our trace will always start with the CPU change event or would it be possible that we won't know the CPU id until the first context switch occurs?

lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.cpp

81–88

afaiu, we use pretty much the same data structures to keep track of TSCs and CPU Ids. Is there a reason that the TSC structures live on the trace cursor whereas the CPU id structures live on the decoded thread itself?
Wondering if it would make more sense to move the TSC structures off of the trace cursor and be consistent with how it's done for CPU Ids.
wdyt?

lldb/source/Target/TraceDumper.cpp

137–141

What about making an EventToString that abstracts away the details of how to print an event? Basically the same as EventKindToString but have it take in an item instead of event kind.
Otherwise, we will have to continue adding logic here for each new event/any modifications to existing events

204–206

similar suggestions as above about potentially moving all of this logic into a single function, maybe in this case it could be EventToJson or something similar and it takes in a ref to the json as well as the item

[wallace]

lldb/source/Plugins/Trace/intel-pt/LibiptDecoder.cpp

288

for per-cpu tracing, we'll always have the cpu change event as the first trace item. For per-thread tracing, we won't have this

lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.cpp

81–88

I've been trying different ways of storing the data and exposing them, so that's why you see some inconsistencies. And yes, we should things the same way we we've doing it for CPUs, but I'll leave it for a future diff, in which we also decide how we are going to expose TSCs and nanoseconds in the trace cursor.

lldb/source/Target/TraceDumper.cpp

137–141

i think that won't be needed now because i don't see any other part of LLDB dumping this information in a string format. Other external consumers would probably have their own format for this data

204–206

again, i don't see this being reused in other parts of LLDB, so I don't think it's worth doing the abstractions

[jj10306]

thanks for following up on those questions, lgtm

lldb/include/lldb/Target/TraceCursor.h

public:
   /// associated with them.
   ///
   /// \param[in] counter_type
   ///    The counter type.
   /// \return
   ///    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:
   ExecutionContextRef m_exe_ctx_ref;
   bool m_forwards = false;
 };
 } // namespace lldb_private
 
 #endif // LLDB_TARGET_TRACE_CURSOR_H

lldb/include/lldb/Target/TraceDumper.h

public:
   struct TraceItem {
     lldb::user_id_t id;
     lldb::addr_t load_address;
     llvm::Optional<uint64_t> tsc;
     llvm::Optional<llvm::StringRef> error;
     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
   /// information will be dumped.
   class OutputWriter {
   public:
     virtual ~OutputWriter() = default;
 

lldb/include/lldb/lldb-enumerations.h

 };
 
 // Type of counter values associated with instructions in a trace.
 enum TraceCounter {
   // Timestamp counter, like the one offered by Intel CPUs (TSC).
   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
 enum TraceItemKind {
   eTraceItemKindError = 0,
   eTraceItemKindEvent,
   eTraceItemKindInstruction,
 };
 
 } // namespace lldb
 
 #endif // LLDB_LLDB_ENUMERATIONS_H

lldb/source/Plugins/Trace/intel-pt/DecodedThread.h

public:
   /// \return
   ///   The trace item kind given an item index.
   lldb::TraceItemKind GetItemKindByIndex(size_t item_index) const;
 
   /// \return
   ///   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;
 
   /// Get a new cursor for the decoded thread.
   lldb::TraceCursorUP CreateNewCursor();
 
   /// Return an object with statistics of the TSC decoding errors that happened.
public:
 
   /// The approximate size in bytes used by this instance,
   /// including all the already decoded instructions.
   size_t CalculateApproximateMemoryUsage() const;
 
   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);
 
   /// Append a custom decoding.
   void AppendCustomError(llvm::StringRef error);
 
   /// Append an event.
   void AppendEvent(lldb::TraceEvent);
private:
   std::vector<uint8_t> m_item_kinds;
 
   /// This map contains the TSCs of the decoded instructions. It maps
   /// `instruction index -> TSC`, where `instruction index` is the first index
   /// at which the mapped TSC appears. We use this representation because TSCs
   /// 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.
   LibiptErrorsStats m_tsc_errors_stats;
   /// Total amount of time spent decoding.
   std::chrono::milliseconds m_total_decoding_time{0};
 };
 
 using DecodedThreadSP = std::shared_ptr<DecodedThread>;
 
 } // namespace trace_intel_pt
 } // namespace lldb_private
 
 #endif // LLDB_SOURCE_PLUGINS_TRACE_INTEL_PT_DECODEDTHREAD_H

lldb/source/Plugins/Trace/intel-pt/DecodedThread.cpp

 DecodedThread::CreateNewTraceItem(lldb::TraceItemKind kind) {
   m_item_kinds.push_back(kind);
   m_item_data.emplace_back();
   return m_item_data.back();
 }
 
 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);
 }
 
 void DecodedThread::AppendInstruction(const pt_insn &insn) {
   CreateNewTraceItem(lldb::eTraceItemKindInstruction).load_address = insn.ip;
 }
else if (insn_index > hint_range->GetEndInstructionIndex())
       candidate_range = hint_range->Next();
     else
       candidate_range = hint_range;
 
     if (candidate_range && candidate_range->InRange(insn_index))
       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);
 }
 
 lldb::TraceItemKind DecodedThread::GetItemKindByIndex(size_t item_index) const {
   return static_cast<lldb::TraceItemKind>(m_item_kinds[item_index]);
 }
 
 const char *DecodedThread::GetErrorByIndex(size_t item_index) const {
   return m_item_data[item_index].error;
 }
 
 DecodedThread::DecodedThread(ThreadSP thread_sp) : m_thread_sp(thread_sp) {}
 
 lldb::TraceCursorUP DecodedThread::CreateNewCursor() {
   return std::make_unique<TraceCursorIntelPT>(m_thread_sp, shared_from_this());
 }
 
 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,
                                   const DecodedThread &decoded_thread)
     : 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;
 }
 
 size_t DecodedThread::TscRange::GetTsc() const { return m_it->second; }
 
 size_t DecodedThread::TscRange::GetStartInstructionIndex() const {
   return m_it->first;
 }
 
 size_t DecodedThread::TscRange::GetEndInstructionIndex() const {
   return m_end_index;
 }
 
 bool DecodedThread::TscRange::InRange(size_t insn_index) const {
   return GetStartInstructionIndex() <= insn_index &&
          insn_index <= GetEndInstructionIndex();
 }
 
 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;
   return TscRange(prev_it, *m_decoded_thread);
 }

lldb/source/Plugins/Trace/intel-pt/LibiptDecoder.cpp

for (auto &cpu_id_buffer : buffers) {
     decoders.try_emplace(cpu_id_buffer.first,
                          LibiptDecoder(*decoder_up->release(), decoded_thread));
   }
 
   bool has_seen_psbs = false;
   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) {
       if (execution.intelpt_subtraces.empty()) {
         decoded_thread.AppendCustomError(
             formatv("Unable to find intel pt data for thread "
                     "execution on cpu id = {0}",
                     execution.thread_execution.cpu_id)

lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.h

public:
 
   lldb::addr_t GetLoadAddress() const override;
 
   llvm::Optional<uint64_t>
   GetCounter(lldb::TraceCounter counter_type) const override;
 
   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;
 
   lldb::user_id_t GetId() const override;
 
   bool HasId(lldb::user_id_t id) const override;
 

lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.cpp

lldb::addr_t TraceCursorIntelPT::GetLoadAddress() const {
   return m_decoded_thread_sp->GetInstructionLoadAddress(m_pos);
 }
 
 Optional<uint64_t>
 TraceCursorIntelPT::GetCounter(lldb::TraceCounter counter_type) const {
   switch (counter_type) {
   case lldb::eTraceCounterTSC:
     if (m_tsc_range)
       return m_tsc_range->GetTsc();
     else
       return llvm::None;
   }
 }
 
+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);
 }
 
 bool TraceCursorIntelPT::GoToId(user_id_t id) {
   if (!HasId(id))
     return false;
   m_pos = id;

lldb/source/Target/TraceCursor.cpp

 }
 
 const char *TraceCursor::EventKindToString(lldb::TraceEvent event_kind) {
   switch (event_kind) {
   case lldb::eTraceEventDisabledHW:
     return "hardware disabled tracing";
   case lldb::eTraceEventDisabledSW:
     return "software disabled tracing";
+  case lldb::eTraceEventCPUChanged:
+    return "CPU core changed";
   }
 }

lldb/source/Target/TraceDumper.cpp

void TraceItem(const TraceDumper::TraceItem &item) override {
     }
 
     if (item.error && !m_was_prev_instruction_an_error)
       m_s << "    ...missing instructions\n";
 
     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 {
       m_s.Format("{0:x+16}", item.load_address);
       if (item.symbol_info) {
         m_s << "    ";
         item.symbol_info->instruction->Dump(&m_s, /*max_opcode_byte_size=*/0,
                                             /*show_address=*/false,
private:
   TraceDumperOptions m_options;
   bool m_was_prev_instruction_an_error = false;
 };
 
 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,
       "symbol"?: string,
       "line"?: decimal,
       "column"?: decimal,
       "source"?: string,
       "mnemonic"?: string,
     }
   */
 public:
   OutputWriterJSON(Stream &s, const TraceDumperOptions &options)
       : m_s(s), m_options(options),
         m_j(m_s.AsRawOstream(),
             /*IndentSize=*/options.pretty_print_json ? 2 : 0) {
     m_j.arrayBegin();
   };
 
   ~OutputWriterJSON() { m_j.arrayEnd(); }
 
-  void TraceItem(const TraceDumper::TraceItem &item) override {
-    m_j.object([&] {
-      m_j.attribute("id", item.id);
-      if (m_options.show_tsc)
-        m_j.attribute(
-            "tsc",
-            item.tsc ? Optional<std::string>(std::to_string(*item.tsc)) : None);
-
-      if (item.event) {
-        m_j.object([&] {
-          m_j.attribute("event", TraceCursor::EventKindToString(*item.event));
-        });
-        return;
-      }
-
-      if (item.error) {
-        m_j.attribute("error", *item.error);
-        return;
-      }
+  void DumpEvent(const TraceDumper::TraceItem &item) {
+    if (item.event == eTraceEventCPUChanged)
+      m_j.attribute("cpuId", item.cpu_id);
 
-      // we know we are seeing an actual instruction
-      m_j.attribute("loadAddress", formatv("{0:x}", item.load_address));
-      if (item.symbol_info) {
-        m_j.attribute("module", ToOptionalString(GetModuleName(item)));
-        m_j.attribute("symbol",
-                      ToOptionalString(
-                          item.symbol_info->sc.GetFunctionName().AsCString()));
-        m_j.attribute(
-            "mnemonic",
+  void DumpInstruction(const TraceDumper::TraceItem &item) {
+          "symbol",
+          ToOptionalString(item.symbol_info->sc.GetFunctionName().AsCString()));
+      m_j.attribute("mnemonic",
                     ToOptionalString(item.symbol_info->instruction->GetMnemonic(
                         &item.symbol_info->exe_ctx)));
 
-        if (IsLineEntryValid(item.symbol_info->sc.line_entry)) {
-          m_j.attribute(
-              "source",
-              ToOptionalString(
-                  item.symbol_info->sc.line_entry.file.GetPath().c_str()));
-          m_j.attribute("line", item.symbol_info->sc.line_entry.line);
-          m_j.attribute("column", item.symbol_info->sc.line_entry.column);
-        }
-      }
+  }
+
+  void TraceItem(const TraceDumper::TraceItem &item) override {
+    m_j.object([&] {
+      m_j.attribute("id", item.id);
+      if (m_options.show_tsc)
+        m_j.attribute(
+            "tsc",
+            item.tsc ? Optional<std::string>(std::to_string(*item.tsc)) : None);
+
+      if (item.event) {
+        DumpEvent(item);
+      } else if (item.error) {
+        m_j.attribute("error", *item.error);
+      } else {
+        DumpInstruction(item);
+      }
     });
   }
 
 private:
   Stream &m_s;
   TraceDumperOptions m_options;
   json::OStream m_j;
 };
for (size_t insn_seen = 0; insn_seen < count && m_cursor_up->HasValue();
 
     last_id = m_cursor_up->GetId();
     TraceItem item = CreatRawTraceItem();
 
     if (m_cursor_up->IsEvent()) {
       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 {
       insn_seen++;
       item.load_address = m_cursor_up->GetLoadAddress();
 
       if (!m_options.raw) {
         SymbolInfo symbol_info;

lldb/test/API/commands/trace/TestTraceEvents.py

 import lldb
 from intelpt_testcase import *
 from lldbsuite.test.lldbtest import *
 from lldbsuite.test import lldbutil
 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):
       '''
         Everytime the target stops running on the CPU, a 'disabled' event will
         be emitted, which is represented by the TraceCursor API as a 'paused'
         event.
       '''
       self.expect("target create " +
             os.path.join(self.getSourceDir(), "intelpt-trace-multi-file", "a.out"))

lldb/test/API/commands/trace/TestTraceLoad.py

 import lldb
 from intelpt_testcase import *
 from lldbsuite.test.lldbtest import *
 from lldbsuite.test import lldbutil
 from lldbsuite.test.decorators import *
 
 class TestTraceLoad(TraceIntelPTTestCaseBase):
     NO_DEBUG_INFO_TESTCASE = True
 
     @testSBAPIAndCommands
     def testLoadMultiCoreTrace(self):
         src_dir = self.getSourceDir()
         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,
class TestTraceLoad(TraceIntelPTTestCaseBase):
   }
 }'''])
 
         self.expect("thread trace dump info 2 --json",
           substrs=['''{
   "traceTechnology": "intel-pt",
   "threadStats": {
     "tid": 3497496,
-    "traceItemsCount": 19523,
+    "traceItemsCount": 19524,
     "memoryUsage": {
-      "totalInBytes": "175739",
+      "totalInBytes": "175760",
       "avgPerItemInBytes": 9.00''', '''},
     "timingInSeconds": {},
     "events": {
-      "totalCount": 1,
+      "totalCount": 2,
       "individualCounts": {
-        "software disabled tracing": 1
+        "software disabled tracing": 1,
+        "CPU core changed": 1
       }
     },
     "continuousExecutions": 1,
     "PSBBlocks": 1,
     "errorItems": {
       "total": 0,
       "individualErrors": {}
     }

 }'''])
 
     @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
     def testLoadMultiCoreTraceWithMissingThreads(self):
         src_dir = self.getSourceDir()
         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
     def testLoadTrace(self):
         src_dir = self.getSourceDir()
         trace_description_file_path = os.path.join(src_dir, "intelpt-trace", "trace.json")
         self.traceLoad(traceDescriptionFilePath=trace_description_file_path, substrs=["intel-pt"])