This revision was landed with ongoing or failed builds.
This revision was automatically updated to reflect the committed changes.
Closed by commit rG4a843d928275: [trace][intel pt] Create a CPU change event
and expose it in the dumper (authored by Walter Erquinigo
<wall...@fb.com>).
Changed prior to commit:
https://reviews.llvm.org/D129340?vs=443104&id=444385#toc
Repository:
rG LLVM Github Monorepo
CHANGES SINCE LAST ACTION
https://reviews.llvm.org/D129340/new/
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,13 +13,80 @@
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 @@
# 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 @@
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,
@@ -202,6 +202,11 @@
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 @@
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 @@
if (item.event) {
DumpEvent(item);
+<<<<<<< HEAD
return;
}
@@ -249,6 +261,13 @@
// 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 @@
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
@@ -1163,12 +1163,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
@@ -66,6 +66,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
