wallace created this revision.
wallace added reviewers: jj10306, persona0220.
Herald added a project: All.
wallace requested review of this revision.
Herald added a project: LLDB.
Herald added a subscriber: lldb-commits.
Thanks to fredz...@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.
Repository:
rG LLVM Github Monorepo
https://reviews.llvm.org/D129340
Files:
lldb/include/lldb/Target/TraceCursor.h
lldb/include/lldb/Target/TraceDumper.h
lldb/include/lldb/lldb-enumerations.h
lldb/source/Plugins/Trace/intel-pt/DecodedThread.cpp
lldb/source/Plugins/Trace/intel-pt/DecodedThread.h
lldb/source/Plugins/Trace/intel-pt/LibiptDecoder.cpp
lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.cpp
lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.h
lldb/source/Target/TraceCursor.cpp
lldb/source/Target/TraceDumper.cpp
lldb/test/API/commands/trace/TestTraceEvents.py
lldb/test/API/commands/trace/TestTraceLoad.py
Index: lldb/test/API/commands/trace/TestTraceLoad.py
===================================================================
--- lldb/test/API/commands/trace/TestTraceLoad.py
+++ lldb/test/API/commands/trace/TestTraceLoad.py
@@ -13,11 +13,11 @@
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",
@@ -58,15 +58,16 @@
"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,
@@ -92,11 +93,11 @@
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
@@ -105,11 +106,11 @@
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
Index: lldb/test/API/commands/trace/TestTraceEvents.py
===================================================================
--- lldb/test/API/commands/trace/TestTraceEvents.py
+++ lldb/test/API/commands/trace/TestTraceEvents.py
@@ -6,6 +6,23 @@
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):
'''
Index: lldb/source/Target/TraceDumper.cpp
===================================================================
--- lldb/source/Target/TraceDumper.cpp
+++ lldb/source/Target/TraceDumper.cpp
@@ -129,18 +129,16 @@
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 @@
/* 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,
@@ -200,6 +200,34 @@
~OutputWriterJSON() { m_j.arrayEnd(); }
+ void DumpEvent(const TraceDumper::TraceItem &item) {
+ m_j.attribute("event", TraceCursor::EventKindToString(*item.event));
+ if (item.event == eTraceEventCPUChanged)
+ m_j.attribute("cpuId", item.cpu_id);
+ }
+
+ void DumpInstruction(const TraceDumper::TraceItem &item) {
+ 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",
+ 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);
@@ -209,37 +237,11 @@
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) {
+ DumpEvent(item);
+ } else if (item.error) {
m_j.attribute("error", *item.error);
- return;
- }
-
- // 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",
- 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);
- }
+ } else {
+ DumpInstruction(item);
}
});
}
@@ -361,6 +363,8 @@
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 {
Index: lldb/source/Target/TraceCursor.cpp
===================================================================
--- lldb/source/Target/TraceCursor.cpp
+++ lldb/source/Target/TraceCursor.cpp
@@ -48,5 +48,7 @@
return "hardware disabled tracing";
case lldb::eTraceEventDisabledSW:
return "software disabled tracing";
+ case lldb::eTraceEventCPUChanged:
+ return "CPU core changed";
}
}
Index: lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.h
===================================================================
--- lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.h
+++ lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.h
@@ -34,6 +34,8 @@
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;
Index: lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.cpp
===================================================================
--- lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.cpp
+++ lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.cpp
@@ -84,6 +84,10 @@
}
}
+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);
}
Index: lldb/source/Plugins/Trace/intel-pt/LibiptDecoder.cpp
===================================================================
--- lldb/source/Plugins/Trace/intel-pt/LibiptDecoder.cpp
+++ lldb/source/Plugins/Trace/intel-pt/LibiptDecoder.cpp
@@ -285,6 +285,8 @@
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) {
Index: lldb/source/Plugins/Trace/intel-pt/DecodedThread.h
===================================================================
--- lldb/source/Plugins/Trace/intel-pt/DecodedThread.h
+++ lldb/source/Plugins/Trace/intel-pt/DecodedThread.h
@@ -168,6 +168,15 @@
/// 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 @@
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 @@
/// 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.
Index: lldb/source/Plugins/Trace/intel-pt/DecodedThread.cpp
===================================================================
--- lldb/source/Plugins/Trace/intel-pt/DecodedThread.cpp
+++ lldb/source/Plugins/Trace/intel-pt/DecodedThread.cpp
@@ -63,11 +63,28 @@
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 @@
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 @@
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 @@
: 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 @@
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;
Index: lldb/include/lldb/lldb-enumerations.h
===================================================================
--- lldb/include/lldb/lldb-enumerations.h
+++ lldb/include/lldb/lldb-enumerations.h
@@ -1153,12 +1153,15 @@
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
Index: lldb/include/lldb/Target/TraceDumper.h
===================================================================
--- lldb/include/lldb/Target/TraceDumper.h
+++ lldb/include/lldb/Target/TraceDumper.h
@@ -64,6 +64,7 @@
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
Index: lldb/include/lldb/Target/TraceCursor.h
===================================================================
--- lldb/include/lldb/Target/TraceCursor.h
+++ lldb/include/lldb/Target/TraceCursor.h
@@ -266,6 +266,16 @@
/// 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:
_______________________________________________
lldb-commits mailing list
lldb-commits@lists.llvm.org
https://lists.llvm.org/cgi-bin/mailman/listinfo/lldb-commits
