[Lldb-commits] [lldb] 059f39d - [trace][intel pt] Support events
Walter Erquinigo via lldb-commits
lldb-commits at lists.llvm.org
Mon Apr 25 19:10:47 PDT 2022
Author: Walter Erquinigo
Date: 2022-04-25T19:01:23-07:00
New Revision: 059f39d2f44503862cb9c752c28a3a77275b0e51
URL: https://github.com/llvm/llvm-project/commit/059f39d2f44503862cb9c752c28a3a77275b0e51
DIFF: https://github.com/llvm/llvm-project/commit/059f39d2f44503862cb9c752c28a3a77275b0e51.diff
LOG: [trace][intel pt] Support events
A trace might contain events traced during the target's execution. For
example, a thread might be paused for some period of time due to context
switches or breakpoints, which actually force a context switch. Not only
that, a trace might be paused because the CPU decides to trace only a
specific part of the target, like the address filtering provided by
intel pt, which will cause pause events. Besides this case, other kinds
of events might exist.
This patch adds the method `TraceCursor::GetEvents()`` that returns the
list of events that happened right before the instruction being pointed
at by the cursor. Some refactors were done to make this change simpler.
Besides this new API, the instruction dumper now supports the -e flag
which shows pause events, like in the following example, where pauses
happened due to breakpoints.
```
thread #1: tid = 2717361
a.out`main + 20 at main.cpp:27:20
0: 0x00000000004023d9 leaq -0x1200(%rbp), %rax
[paused]
1: 0x00000000004023e0 movq %rax, %rdi
[paused]
2: 0x00000000004023e3 callq 0x403a62 ; std::vector<int, std::allocator<int> >::vector at stl_vector.h:391:7
a.out`std::vector<int, std::allocator<int> >::vector() at stl_vector.h:391:7
3: 0x0000000000403a62 pushq %rbp
4: 0x0000000000403a63 movq %rsp, %rbp
```
The `dump info` command has also been updated and now it shows the
number of instructions that have associated events.
Differential Revision: https://reviews.llvm.org/D123982
Added:
lldb/test/API/commands/trace/TestTraceEvents.py
Modified:
lldb/include/lldb/Target/TraceCursor.h
lldb/include/lldb/Target/TraceInstructionDumper.h
lldb/include/lldb/lldb-enumerations.h
lldb/source/Commands/CommandObjectThread.cpp
lldb/source/Commands/Options.td
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/ThreadDecoder.cpp
lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.cpp
lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.h
lldb/source/Plugins/Trace/intel-pt/TraceIntelPT.cpp
lldb/source/Target/TraceCursor.cpp
lldb/source/Target/TraceInstructionDumper.cpp
lldb/test/API/commands/trace/TestTraceDumpInfo.py
lldb/test/API/commands/trace/TestTraceLoad.py
Removed:
################################################################################
diff --git a/lldb/include/lldb/Target/TraceCursor.h b/lldb/include/lldb/Target/TraceCursor.h
index 710bb963a4aa9..606f6886964a7 100644
--- a/lldb/include/lldb/Target/TraceCursor.h
+++ b/lldb/include/lldb/Target/TraceCursor.h
@@ -234,9 +234,17 @@ class TraceCursor {
/// \param[in] counter_type
/// The counter type.
/// \return
- /// The value of the counter or \b llvm::None if not available.
+ /// The value of the counter or \b llvm::None if not available.
virtual llvm::Optional<uint64_t> GetCounter(lldb::TraceCounter counter_type) = 0;
+ /// Get a bitmask with a list of events that happened chronologically right
+ /// before the current instruction or error, but after the previous
+ /// instruction.
+ ///
+ /// \return
+ /// The bitmask of events.
+ virtual lldb::TraceEvents GetEvents() = 0;
+
/// \return
/// The \a lldb::TraceInstructionControlFlowType categories the
/// instruction the cursor is pointing at falls into. If the cursor points
@@ -254,6 +262,29 @@ class TraceCursor {
bool m_forwards = false;
};
+namespace trace_event_utils {
+/// Convert an individual event to a display string.
+///
+/// \param[in] event
+/// An individual event.
+///
+/// \return
+/// A display string for that event, or nullptr if wrong data is passed
+/// in.
+const char *EventToDisplayString(lldb::TraceEvents event);
+
+/// Invoke the given callback for each individual event of the given events
+/// bitmask.
+///
+/// \param[in] events
+/// A list of events to inspect.
+///
+/// \param[in] callback
+/// The callback to invoke for each event.
+void ForEachEvent(lldb::TraceEvents events,
+ std::function<void(lldb::TraceEvents event)> callback);
+} // namespace trace_event_utils
+
} // namespace lldb_private
#endif // LLDB_TARGET_TRACE_CURSOR_H
diff --git a/lldb/include/lldb/Target/TraceInstructionDumper.h b/lldb/include/lldb/Target/TraceInstructionDumper.h
index f66509e462dd4..9dc8e4c50f428 100644
--- a/lldb/include/lldb/Target/TraceInstructionDumper.h
+++ b/lldb/include/lldb/Target/TraceInstructionDumper.h
@@ -26,6 +26,8 @@ struct TraceInstructionDumperOptions {
/// For each instruction, print the corresponding timestamp counter if
/// available.
bool show_tsc = false;
+ /// Dump the events that happened between instructions.
+ bool show_events = false;
/// Optional custom id to start traversing from.
llvm::Optional<uint64_t> id = llvm::None;
/// Optional number of instructions to skip from the starting position
@@ -79,6 +81,8 @@ class TraceInstructionDumper {
/// \b true if the cursor moved.
bool TryMoveOneStep();
+ void PrintEvents();
+
lldb::TraceCursorUP m_cursor_up;
TraceInstructionDumperOptions m_options;
Stream &m_s;
diff --git a/lldb/include/lldb/lldb-enumerations.h b/lldb/include/lldb/lldb-enumerations.h
index 294c68d54fd0c..41dbeebad9b05 100644
--- a/lldb/include/lldb/lldb-enumerations.h
+++ b/lldb/include/lldb/lldb-enumerations.h
@@ -1147,6 +1147,15 @@ enum TraceCounter {
eTraceCounterTSC,
};
+// Events that might happen during a trace session.
+FLAGS_ENUM(TraceEvents){
+ // Tracing was paused. If instructions were executed after pausing
+ // and before resuming, the TraceCursor used to traverse the trace
+ // should provide an error signalinig this data loss.
+ eTraceEventPaused = (1u << 0),
+};
+LLDB_MARK_AS_BITMASK_ENUM(TraceEvents)
+
} // namespace lldb
#endif // LLDB_LLDB_ENUMERATIONS_H
diff --git a/lldb/source/Commands/CommandObjectThread.cpp b/lldb/source/Commands/CommandObjectThread.cpp
index 78ec5409eb7a5..95a8301a318a3 100644
--- a/lldb/source/Commands/CommandObjectThread.cpp
+++ b/lldb/source/Commands/CommandObjectThread.cpp
@@ -2156,6 +2156,10 @@ class CommandObjectTraceDumpInstructions : public CommandObjectParsed {
m_dumper_options.show_tsc = true;
break;
}
+ case 'e': {
+ m_dumper_options.show_events = true;
+ break;
+ }
case 'C': {
m_continue = true;
break;
diff --git a/lldb/source/Commands/Options.td b/lldb/source/Commands/Options.td
index bea4ff510b2ca..f7b6b09b08d20 100644
--- a/lldb/source/Commands/Options.td
+++ b/lldb/source/Commands/Options.td
@@ -1121,12 +1121,15 @@ let Command = "thread trace dump instructions" in {
def thread_trace_dump_instructions_show_tsc : Option<"tsc", "t">, Group<1>,
Desc<"For each instruction, print the corresponding timestamp counter if "
"available.">;
+ def thread_trace_dump_instructions_hide_events : Option<"events", "e">,
+ Group<1>,
+ Desc<"Dump the events that happened during the execution of the target.">;
def thread_trace_dump_instructions_continue: Option<"continue", "C">,
Group<1>,
- Desc<"Continue dumping instructions right where the previous invocation of this "
- "command was left, or from the beginning if this is the first invocation. The --skip "
- "argument is discarded and the other arguments are preserved from the previous "
- "invocation when possible.">;
+ Desc<"Continue dumping instructions right where the previous invocation of "
+ "this command was left, or from the beginning if this is the first "
+ "invocation. The --skip argument is discarded and the other arguments are "
+ "preserved from the previous invocation when possible.">;
}
let Command = "thread trace dump info" in {
diff --git a/lldb/source/Plugins/Trace/intel-pt/DecodedThread.cpp b/lldb/source/Plugins/Trace/intel-pt/DecodedThread.cpp
index 651af3ea5b0cb..73d4f351fec41 100644
--- a/lldb/source/Plugins/Trace/intel-pt/DecodedThread.cpp
+++ b/lldb/source/Plugins/Trace/intel-pt/DecodedThread.cpp
@@ -19,6 +19,18 @@ using namespace lldb_private;
using namespace lldb_private::trace_intel_pt;
using namespace llvm;
+bool lldb_private::trace_intel_pt::IsLibiptError(int libipt_status) {
+ return libipt_status < 0;
+}
+
+bool lldb_private::trace_intel_pt::IsEndOfStream(int libipt_status) {
+ return libipt_status == -pte_eos;
+}
+
+bool lldb_private::trace_intel_pt::IsTscUnavailable(int libipt_status) {
+ return libipt_status == -pte_no_time;
+}
+
char IntelPTError::ID;
IntelPTError::IntelPTError(int libipt_error_code, lldb::addr_t address)
@@ -35,6 +47,10 @@ void IntelPTError::log(llvm::raw_ostream &OS) const {
OS << "error: " << libipt_error_message;
}
+DecodedInstruction::operator bool() const {
+ return !IsLibiptError(libipt_error);
+}
+
size_t DecodedThread::GetInstructionsCount() const {
return m_instruction_ips.size();
}
@@ -93,15 +109,26 @@ void DecodedThread::RecordTscForLastInstruction(uint64_t tsc) {
}
}
-void DecodedThread::AppendInstruction(const pt_insn &insn) {
- m_instruction_ips.emplace_back(insn.ip);
- m_instruction_sizes.emplace_back(insn.size);
- m_instruction_classes.emplace_back(insn.iclass);
-}
+void DecodedThread::Append(const DecodedInstruction &insn) {
+ if (!insn) {
+ // End of stream shouldn't be a public error
+ if (IsEndOfStream(insn.libipt_error))
+ return;
+
+ AppendError(make_error<IntelPTError>(insn.libipt_error, insn.pt_insn.ip));
+ } else {
+ m_instruction_ips.emplace_back(insn.pt_insn.ip);
+ m_instruction_sizes.emplace_back(insn.pt_insn.size);
+ m_instruction_classes.emplace_back(insn.pt_insn.iclass);
+ }
-void DecodedThread::AppendInstruction(const pt_insn &insn, uint64_t tsc) {
- AppendInstruction(insn);
- RecordTscForLastInstruction(tsc);
+ if (insn.tsc)
+ RecordTscForLastInstruction(*insn.tsc);
+
+ if (insn.events) {
+ m_events.try_emplace(m_instruction_ips.size() - 1, insn.events);
+ m_events_stats.RecordEventsForInstruction(insn.events);
+ }
}
void DecodedThread::AppendError(llvm::Error &&error) {
@@ -111,22 +138,45 @@ void DecodedThread::AppendError(llvm::Error &&error) {
m_instruction_classes.emplace_back(pt_insn_class::ptic_error);
}
-void DecodedThread::AppendError(llvm::Error &&error, uint64_t tsc) {
+void DecodedThread::SetAsFailed(llvm::Error &&error) {
AppendError(std::move(error));
- RecordTscForLastInstruction(tsc);
}
-void DecodedThread::LibiptErrors::RecordError(int libipt_error_code) {
- libipt_errors[pt_errstr(pt_errcode(libipt_error_code))]++;
+lldb::TraceEvents DecodedThread::GetEvents(int insn_index) {
+ auto it = m_events.find(insn_index);
+ if (it != m_events.end())
+ return it->second;
+ return (TraceEvents)0;
+}
+
+void DecodedThread::LibiptErrorsStats::RecordError(int libipt_error_code) {
+ libipt_errors_counts[pt_errstr(pt_errcode(libipt_error_code))]++;
total_count++;
}
void DecodedThread::RecordTscError(int libipt_error_code) {
- m_tsc_errors.RecordError(libipt_error_code);
+ m_tsc_errors_stats.RecordError(libipt_error_code);
}
-const DecodedThread::LibiptErrors &DecodedThread::GetTscErrors() const {
- return m_tsc_errors;
+const DecodedThread::LibiptErrorsStats &
+DecodedThread::GetTscErrorsStats() const {
+ return m_tsc_errors_stats;
+}
+
+const DecodedThread::EventsStats &DecodedThread::GetEventsStats() const {
+ return m_events_stats;
+}
+
+void DecodedThread::EventsStats::RecordEventsForInstruction(
+ lldb::TraceEvents events) {
+ if (!events)
+ return;
+
+ total_instructions_with_events++;
+ trace_event_utils::ForEachEvent(events, [&](TraceEvents event) {
+ events_counts[event]++;
+ total_count++;
+ });
}
Optional<DecodedThread::TscRange> DecodedThread::CalculateTscRange(
@@ -187,7 +237,7 @@ size_t DecodedThread::CalculateApproximateMemoryUsage() const {
sizeof(pt_insn::size) * m_instruction_sizes.size() +
sizeof(pt_insn::iclass) * m_instruction_classes.size() +
(sizeof(size_t) + sizeof(uint64_t)) * m_instruction_timestamps.size() +
- m_errors.getMemorySize();
+ m_errors.getMemorySize() + m_events.getMemorySize();
}
DecodedThread::TscRange::TscRange(std::map<size_t, uint64_t>::const_iterator it,
diff --git a/lldb/source/Plugins/Trace/intel-pt/DecodedThread.h b/lldb/source/Plugins/Trace/intel-pt/DecodedThread.h
index 3f28afc658b60..d7654181f3650 100644
--- a/lldb/source/Plugins/Trace/intel-pt/DecodedThread.h
+++ b/lldb/source/Plugins/Trace/intel-pt/DecodedThread.h
@@ -23,6 +23,15 @@
namespace lldb_private {
namespace trace_intel_pt {
+/// libipt status utils
+/// \{
+bool IsLibiptError(int libipt_status);
+
+bool IsEndOfStream(int libipt_status);
+
+bool IsTscUnavailable(int libipt_status);
+/// \}
+
/// Class for representing a libipt decoding error.
class IntelPTError : public llvm::ErrorInfo<IntelPTError> {
public:
@@ -51,6 +60,27 @@ class IntelPTError : public llvm::ErrorInfo<IntelPTError> {
lldb::addr_t m_address;
};
+/// Helper struct for building an instruction or error from the decoder.
+/// It holds associated events and timing information.
+struct DecodedInstruction {
+ DecodedInstruction() {
+ pt_insn.ip = LLDB_INVALID_ADDRESS;
+ libipt_error = pte_ok;
+ }
+
+ DecodedInstruction(int libipt_error_code) : DecodedInstruction() {
+ libipt_error = libipt_error_code;
+ }
+
+ /// \return \b true if and only if this struct holds a libipt error.
+ explicit operator bool() const;
+
+ int libipt_error;
+ lldb::TraceEvents events = (lldb::TraceEvents)0;
+ llvm::Optional<uint64_t> tsc = llvm::None;
+ pt_insn pt_insn;
+};
+
/// \class DecodedThread
/// Class holding the instructions and function call hierarchy obtained from
/// decoding a trace, as well as a position cursor used when reverse debugging
@@ -101,30 +131,40 @@ class DecodedThread : public std::enable_shared_from_this<DecodedThread> {
};
// Struct holding counts for libipts errors;
- struct LibiptErrors {
+ struct LibiptErrorsStats {
// libipt error -> count
- llvm::DenseMap<const char *, int> libipt_errors;
- int total_count = 0;
+ llvm::DenseMap<const char *, int> libipt_errors_counts;
+ size_t total_count = 0;
void RecordError(int libipt_error_code);
};
+ // Struct holding counts for events;
+ struct EventsStats {
+ /// A count for each individual event kind. We use an unordered map instead
+ /// of a DenseMap because DenseMap can't understand enums.
+ std::unordered_map<lldb::TraceEvents, size_t> events_counts;
+ size_t total_count = 0;
+ size_t total_instructions_with_events = 0;
+
+ void RecordEventsForInstruction(lldb::TraceEvents events);
+ };
+
DecodedThread(lldb::ThreadSP thread_sp);
/// Utility constructor that initializes the trace with a provided error.
DecodedThread(lldb::ThreadSP thread_sp, llvm::Error &&err);
- /// Append a successfully decoded instruction.
- void AppendInstruction(const pt_insn &instruction);
+ /// Append an instruction or a libipt error.
+ void Append(const DecodedInstruction &insn);
- /// Append a sucessfully decoded instruction with an associated TSC timestamp.
- void AppendInstruction(const pt_insn &instruction, uint64_t tsc);
-
- /// Append a decoding error (i.e. an instruction that failed to be decoded).
- void AppendError(llvm::Error &&error);
+ /// Append an error signaling that decoding completely failed.
+ void SetAsFailed(llvm::Error &&error);
- /// Append a decoding error with a corresponding TSC.
- void AppendError(llvm::Error &&error, uint64_t tsc);
+ /// Get a bitmask with the events that happened chronologically right before
+ /// the instruction pointed by the given instruction index, but after the
+ /// previous instruction.
+ lldb::TraceEvents GetEvents(int insn_index);
/// Get the total number of instruction pointers from the decoded trace.
/// This will include instructions that indicate errors (or gaps) in the
@@ -175,13 +215,19 @@ class DecodedThread : public std::enable_shared_from_this<DecodedThread> {
/// Get a new cursor for the decoded thread.
lldb::TraceCursorUP GetCursor();
- /// Return the number of TSC decoding errors that happened. A TSC error
- /// is not a fatal error and doesn't create gaps in the trace. Instead
- /// we only keep track of them as a statistic.
+ /// Return an object with statistics of the TSC decoding errors that happened.
+ /// A TSC error is not a fatal error and doesn't create gaps in the trace.
+ /// Instead we only keep track of them as statistics.
///
/// \return
- /// The number of TSC decoding errors.
- const LibiptErrors &GetTscErrors() const;
+ /// An object with the statistics of TSC decoding errors.
+ const LibiptErrorsStats &GetTscErrorsStats() const;
+
+ /// Return an object with statistics of the trace events that happened.
+ ///
+ /// \return
+ /// The stats object of all the events.
+ const EventsStats &GetEventsStats() const;
/// Record an error decoding a TSC timestamp.
///
@@ -198,6 +244,9 @@ class DecodedThread : public std::enable_shared_from_this<DecodedThread> {
lldb::ThreadSP GetThread();
private:
+ /// Append a decoding error given an llvm::Error.
+ void AppendError(llvm::Error &&error);
+
/// Notify this class that the last added instruction or error has
/// an associated TSC.
void RecordTscForLastInstruction(uint64_t tsc);
@@ -219,17 +268,20 @@ class DecodedThread : public std::enable_shared_from_this<DecodedThread> {
/// 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<size_t, uint64_t> m_instruction_timestamps;
+ std::map<uint64_t, uint64_t> m_instruction_timestamps;
/// This is the chronologically last TSC that has been added.
llvm::Optional<uint64_t> m_last_tsc = llvm::None;
// This variables stores the messages of all the error instructions in the
// trace. It maps `instruction index -> error message`.
llvm::DenseMap<uint64_t, std::string> m_errors;
- /// The size in bytes of the raw buffer before decoding. It might be None if
- /// the decoding failed.
- llvm::Optional<size_t> m_raw_trace_size;
- /// All occurrences of libipt errors when decoding TSCs.
- LibiptErrors m_tsc_errors;
+ /// This variable stores the bitmask of events that happened right before
+ /// the instruction given as a key. It maps `instruction index -> events`.
+ llvm::DenseMap<uint64_t, lldb::TraceEvents> m_events;
+
+ /// 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};
};
diff --git a/lldb/source/Plugins/Trace/intel-pt/LibiptDecoder.cpp b/lldb/source/Plugins/Trace/intel-pt/LibiptDecoder.cpp
index a56d761086541..913db5eefc4ea 100644
--- a/lldb/source/Plugins/Trace/intel-pt/LibiptDecoder.cpp
+++ b/lldb/source/Plugins/Trace/intel-pt/LibiptDecoder.cpp
@@ -26,18 +26,6 @@ struct TscInfo {
explicit operator bool() const { return has_tsc == eLazyBoolYes; }
};
-static inline bool IsLibiptError(int libipt_status) {
- return libipt_status < 0;
-}
-
-static inline bool IsEndOfStream(int libipt_status) {
- return libipt_status == -pte_eos;
-}
-
-static inline bool IsTscUnavailable(int libipt_status) {
- return libipt_status == -pte_no_time;
-}
-
/// Class that decodes a raw buffer for a single thread using the low level
/// libipt library.
///
@@ -75,20 +63,33 @@ class LibiptDecoder {
}
private:
+ /// Invoke the low level function \a pt_insn_next and store the decoded
+ /// instruction in the given \a DecodedInstruction.
+ ///
+ /// \param[out] insn
+ /// The instruction builder where the pt_insn information will be stored.
+ ///
+ /// \return
+ /// The status returned by pt_insn_next.
+ int DecodeNextInstruction(DecodedInstruction &insn) {
+ return pt_insn_next(&m_decoder, &insn.pt_insn, sizeof(insn.pt_insn));
+ }
+
/// Decode all the instructions and events until an error is found or the end
/// of the trace is reached.
///
/// \param[in] status
/// The status that was result of synchronizing to the most recent PSB.
void DecodeInstructionsAndEvents(int status) {
- pt_insn insn;
- while (ProcessPTEvents(status)) {
- status = pt_insn_next(&m_decoder, &insn, sizeof(insn));
- // The status returned by pt_insn_next will need to be processed by
- // ProcessPTEvents in the next loop.
- if (FoundErrors(status, insn.ip))
+ while (DecodedInstruction insn = ProcessPTEvents(status)) {
+ // The status returned by DecodeNextInstruction will need to be processed
+ // by ProcessPTEvents in the next loop if it is not an error.
+ if (IsLibiptError(status = DecodeNextInstruction(insn))) {
+ insn.libipt_error = status;
+ m_decoded_thread.Append(insn);
break;
- AppendInstruction(insn);
+ }
+ m_decoded_thread.Append(insn);
}
}
@@ -98,6 +99,8 @@ class LibiptDecoder {
/// Once the decoder is at that synchronization point, it can start decoding
/// instructions.
///
+ /// If errors are found, they will be appended to the trace.
+ ///
/// \return
/// The libipt decoder status after moving to the next PSB. Negative if
/// no PSB was found.
@@ -135,7 +138,9 @@ class LibiptDecoder {
}
// We make this call to record any synchronization errors.
- FoundErrors(status);
+ if (IsLibiptError(status))
+ m_decoded_thread.Append(DecodedInstruction(status));
+
return status;
}
@@ -143,21 +148,60 @@ class LibiptDecoder {
/// instruction e.g. timing events like ptev_tick, or paging events like
/// ptev_paging.
///
+ /// If an error is found, it will be appended to the trace.
+ ///
+ /// \param[in] status
+ /// The status gotten from the previous instruction decoding or PSB
+ /// synchronization.
+ ///
/// \return
- /// \b true if we could process the events, \b false if errors were found.
- bool ProcessPTEvents(int status) {
+ /// A \a DecodedInstruction with event, tsc and error information.
+ DecodedInstruction ProcessPTEvents(int status) {
+ DecodedInstruction insn;
while (status & pts_event_pending) {
pt_event event;
status = pt_insn_event(&m_decoder, &event, sizeof(event));
- if (IsLibiptError(status))
+ if (IsLibiptError(status)) {
+ insn.libipt_error = status;
break;
+ }
+
+ switch (event.type) {
+ case ptev_enabled:
+ // The kernel started or resumed tracing the program.
+ break;
+ case ptev_disabled:
+ // The CPU paused tracing the program, e.g. due to ip filtering.
+ case ptev_async_disabled:
+ // The kernel or user code paused tracing the program, e.g.
+ // a breakpoint or a ioctl invocation pausing the trace, or a
+ // context switch happened.
+
+ if (m_decoded_thread.GetInstructionsCount() > 0) {
+ // A paused event before the first instruction can be safely
+ // discarded.
+ insn.events |= eTraceEventPaused;
+ }
+ break;
+ case ptev_overflow:
+ // The CPU internal buffer had an overflow error and some instructions
+ // were lost.
+ insn.libipt_error = -pte_overflow;
+ break;
+ default:
+ break;
+ }
}
// We refresh the TSC that might have changed after processing the events.
// See
// https://github.com/intel/libipt/blob/master/doc/man/pt_evt_next.3.md
RefreshTscInfo();
- return !FoundErrors(status);
+ if (m_tsc_info)
+ insn.tsc = m_tsc_info.tsc;
+ if (!insn)
+ m_decoded_thread.Append(insn);
+ return insn;
}
/// Query the decoder for the most recent TSC timestamp and update
@@ -189,39 +233,6 @@ class LibiptDecoder {
}
}
- /// Check if the given libipt status signals any errors. If errors were found,
- /// they will be recorded in the decoded trace.
- ///
- /// \param[in] ip
- /// An optional ip address can be passed if the error is associated with
- /// the decoding of a specific instruction.
- ///
- /// \return
- /// \b true if errors were found, \b false otherwise.
- bool FoundErrors(int status, lldb::addr_t ip = LLDB_INVALID_ADDRESS) {
- if (!IsLibiptError(status))
- return false;
-
- // We signal a gap only if it's not "end of stream", as that's not a proper
- // error.
- if (!IsEndOfStream(status)) {
- if (m_tsc_info) {
- m_decoded_thread.AppendError(make_error<IntelPTError>(status, ip),
- m_tsc_info.tsc);
- } else {
- m_decoded_thread.AppendError(make_error<IntelPTError>(status, ip));
- }
- }
- return true;
- }
-
- void AppendInstruction(const pt_insn &insn) {
- if (m_tsc_info)
- m_decoded_thread.AppendInstruction(insn, m_tsc_info.tsc);
- else
- m_decoded_thread.AppendInstruction(insn);
- }
-
private:
pt_insn_decoder &m_decoder;
DecodedThread &m_decoded_thread;
@@ -293,7 +304,7 @@ void lldb_private::trace_intel_pt::DecodeTrace(DecodedThread &decoded_thread,
Expected<PtInsnDecoderUP> decoder_up =
CreateInstructionDecoder(decoded_thread, trace_intel_pt, buffer);
if (!decoder_up)
- return decoded_thread.AppendError(decoder_up.takeError());
+ return decoded_thread.SetAsFailed(decoder_up.takeError());
LibiptDecoder libipt_decoder(*decoder_up.get(), decoded_thread);
libipt_decoder.DecodeUntilEndOfTrace();
diff --git a/lldb/source/Plugins/Trace/intel-pt/ThreadDecoder.cpp b/lldb/source/Plugins/Trace/intel-pt/ThreadDecoder.cpp
index 50e76ee2a9ee0..1855b07a8f558 100644
--- a/lldb/source/Plugins/Trace/intel-pt/ThreadDecoder.cpp
+++ b/lldb/source/Plugins/Trace/intel-pt/ThreadDecoder.cpp
@@ -43,7 +43,7 @@ DecodedThreadSP ThreadDecoder::DoDecode() {
});
if (err)
- decoded_thread_sp->AppendError(std::move(err));
+ decoded_thread_sp->SetAsFailed(std::move(err));
return decoded_thread_sp;
});
}
diff --git a/lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.cpp b/lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.cpp
index 1adb4b6b578e6..8e02c9f97aec2 100644
--- a/lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.cpp
+++ b/lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.cpp
@@ -108,6 +108,10 @@ TraceCursorIntelPT::GetCounter(lldb::TraceCounter counter_type) {
}
}
+lldb::TraceEvents TraceCursorIntelPT::GetEvents() {
+ return m_decoded_thread_sp->GetEvents(m_pos);
+}
+
TraceInstructionControlFlowType
TraceCursorIntelPT::GetInstructionControlFlowType() {
return m_decoded_thread_sp->GetInstructionControlFlowType(m_pos);
diff --git a/lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.h b/lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.h
index 80e00a832b72d..7b5431ab1822c 100644
--- a/lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.h
+++ b/lldb/source/Plugins/Trace/intel-pt/TraceCursorIntelPT.h
@@ -30,6 +30,8 @@ class TraceCursorIntelPT : public TraceCursor {
llvm::Optional<uint64_t> GetCounter(lldb::TraceCounter counter_type) override;
+ lldb::TraceEvents GetEvents() override;
+
lldb::TraceInstructionControlFlowType
GetInstructionControlFlowType() override;
diff --git a/lldb/source/Plugins/Trace/intel-pt/TraceIntelPT.cpp b/lldb/source/Plugins/Trace/intel-pt/TraceIntelPT.cpp
index 7ee496dd4ba7f..a5def7906dc95 100644
--- a/lldb/source/Plugins/Trace/intel-pt/TraceIntelPT.cpp
+++ b/lldb/source/Plugins/Trace/intel-pt/TraceIntelPT.cpp
@@ -142,11 +142,25 @@ void TraceIntelPT::DumpTraceInfo(Thread &thread, Stream &s, bool verbose) {
s.Format(" {0}: {1:2}s\n", name, duration.count() / 1000.0);
});
+ const DecodedThread::EventsStats &events_stats =
+ decoded_trace_sp->GetEventsStats();
+ s << "\n Events:\n";
+ s.Format(" Number of instructions with events: {0}\n",
+ events_stats.total_instructions_with_events);
+ s.Format(" Number of individual events: {0}\n", events_stats.total_count);
+ for (const auto &event_to_count : events_stats.events_counts) {
+ s.Format(" {0}: {1}\n",
+ trace_event_utils::EventToDisplayString(event_to_count.first),
+ event_to_count.second);
+ }
+
s << "\n Errors:\n";
- const DecodedThread::LibiptErrors &tsc_errors =
- decoded_trace_sp->GetTscErrors();
- s.Format(" Number of TSC decoding errors: {0}\n", tsc_errors.total_count);
- for (const auto &error_message_to_count : tsc_errors.libipt_errors) {
+ const DecodedThread::LibiptErrorsStats &tsc_errors_stats =
+ decoded_trace_sp->GetTscErrorsStats();
+ s.Format(" Number of TSC decoding errors: {0}\n",
+ tsc_errors_stats.total_count);
+ for (const auto &error_message_to_count :
+ tsc_errors_stats.libipt_errors_counts) {
s.Format(" {0}: {1}\n", error_message_to_count.first,
error_message_to_count.second);
}
diff --git a/lldb/source/Target/TraceCursor.cpp b/lldb/source/Target/TraceCursor.cpp
index d0f69642cb90b..23925748dd20b 100644
--- a/lldb/source/Target/TraceCursor.cpp
+++ b/lldb/source/Target/TraceCursor.cpp
@@ -33,3 +33,21 @@ void TraceCursor::SetIgnoreErrors(bool ignore_errors) {
void TraceCursor::SetForwards(bool forwards) { m_forwards = forwards; }
bool TraceCursor::IsForwards() const { return m_forwards; }
+
+const char *trace_event_utils::EventToDisplayString(lldb::TraceEvents event) {
+ switch (event) {
+ case lldb::eTraceEventPaused:
+ return "paused";
+ }
+ return nullptr;
+}
+
+void trace_event_utils::ForEachEvent(
+ lldb::TraceEvents events,
+ std::function<void(lldb::TraceEvents event)> callback) {
+ while (events) {
+ TraceEvents event = static_cast<TraceEvents>(events & ~(events - 1));
+ callback(event);
+ events &= ~event;
+ }
+}
diff --git a/lldb/source/Target/TraceInstructionDumper.cpp b/lldb/source/Target/TraceInstructionDumper.cpp
index 09ff72d0fa1d3..7473e84e356f1 100644
--- a/lldb/source/Target/TraceInstructionDumper.cpp
+++ b/lldb/source/Target/TraceInstructionDumper.cpp
@@ -172,6 +172,16 @@ void TraceInstructionDumper::SetNoMoreData() { m_no_more_data = true; }
bool TraceInstructionDumper::HasMoreData() { return !m_no_more_data; }
+void TraceInstructionDumper::PrintEvents() {
+ if (!m_options.show_events)
+ return;
+
+ trace_event_utils::ForEachEvent(
+ m_cursor_up->GetEvents(), [&](TraceEvents event) {
+ m_s.Format(" [{0}]\n", trace_event_utils::EventToDisplayString(event));
+ });
+}
+
Optional<lldb::tid_t> TraceInstructionDumper::DumpInstructions(size_t count) {
ThreadSP thread_sp = m_cursor_up->GetExecutionContextRef().GetThreadSP();
if (!thread_sp) {
@@ -259,6 +269,11 @@ Optional<lldb::tid_t> TraceInstructionDumper::DumpInstructions(size_t count) {
break;
}
last_id = m_cursor_up->GetId();
+ if (m_options.forwards) {
+ // When moving forwards, we first print the event before printing
+ // the actual instruction.
+ PrintEvents();
+ }
if (const char *err = m_cursor_up->GetError()) {
if (!m_cursor_up->IsForwards() && !was_prev_instruction_an_error)
@@ -297,6 +312,13 @@ Optional<lldb::tid_t> TraceInstructionDumper::DumpInstructions(size_t count) {
}
m_s.Printf("\n");
+
+ if (!m_options.forwards) {
+ // If we move backwards, we print the events after printing
+ // the actual instruction so that reading chronologically
+ // makes sense.
+ PrintEvents();
+ }
TryMoveOneStep();
}
return last_id;
diff --git a/lldb/test/API/commands/trace/TestTraceDumpInfo.py b/lldb/test/API/commands/trace/TestTraceDumpInfo.py
index 059b22f9b6f4d..b24e0964b9041 100644
--- a/lldb/test/API/commands/trace/TestTraceDumpInfo.py
+++ b/lldb/test/API/commands/trace/TestTraceDumpInfo.py
@@ -42,12 +42,17 @@ def testDumpRawTraceSize(self):
Memory usage:
Raw trace size: 4 KiB
- Total approximate memory usage (excluding raw trace): 0.27 KiB
- Average memory usage per instruction (excluding raw trace): 13.00 bytes
+ Total approximate memory usage (excluding raw trace): 1.27 KiB
+ Average memory usage per instruction (excluding raw trace): 61.76 bytes
Timing:
Decoding instructions: ''', '''s
+ Events:
+ Number of instructions with events: 1
+ Number of individual events: 1
+ paused: 1
+
Errors:
Number of TSC decoding errors: 0'''],
patterns=["Decoding instructions: \d.\d\ds"])
diff --git a/lldb/test/API/commands/trace/TestTraceEvents.py b/lldb/test/API/commands/trace/TestTraceEvents.py
new file mode 100644
index 0000000000000..d8c8e6eea8ca4
--- /dev/null
+++ b/lldb/test/API/commands/trace/TestTraceEvents.py
@@ -0,0 +1,82 @@
+import lldb
+from intelpt_testcase import *
+from lldbsuite.test.lldbtest import *
+from lldbsuite.test import lldbutil
+from lldbsuite.test.decorators import *
+
+class TestTraceEvents(TraceIntelPTTestCaseBase):
+
+ mydir = TestBase.compute_mydir(__file__)
+
+ @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"))
+ self.expect("b 12")
+ self.expect("r")
+ self.traceStartThread()
+ self.expect("n")
+ self.expect("n")
+ self.expect("si")
+ self.expect("si")
+ self.expect("si")
+ # We ensure that the paused events are printed correctly forward
+ self.expect("thread trace dump instructions -e -f",
+ patterns=[f'''thread #1: tid = .*
+ a.out`main \+ 23 at main.cpp:12
+ 0: {ADDRESS_REGEX} movl .*
+ \[paused\]
+ 1: {ADDRESS_REGEX} addl .*
+ 2: {ADDRESS_REGEX} movl .*
+ \[paused\]
+ a.out`main \+ 34 \[inlined\] inline_function\(\) at main.cpp:4
+ 3: {ADDRESS_REGEX} movl .*
+ a.out`main \+ 41 \[inlined\] inline_function\(\) \+ 7 at main.cpp:5
+ 4: {ADDRESS_REGEX} movl .*
+ 5: {ADDRESS_REGEX} addl .*
+ 6: {ADDRESS_REGEX} movl .*
+ a.out`main \+ 52 \[inlined\] inline_function\(\) \+ 18 at main.cpp:6
+ 7: {ADDRESS_REGEX} movl .*
+ a.out`main \+ 55 at main.cpp:14
+ 8: {ADDRESS_REGEX} movl .*
+ 9: {ADDRESS_REGEX} addl .*
+ 10: {ADDRESS_REGEX} movl .*
+ \[paused\]
+ a.out`main \+ 63 at main.cpp:16
+ 11: {ADDRESS_REGEX} callq .* ; symbol stub for: foo\(\)
+ \[paused\]
+ a.out`symbol stub for: foo\(\)
+ 12: {ADDRESS_REGEX} jmpq'''])
+
+ # We ensure that the paused events are printed correctly backward
+ self.expect("thread trace dump instructions -e --id 12",
+ patterns=[f'''thread #1: tid = .*
+ a.out`symbol stub for: foo\(\)
+ 12: {ADDRESS_REGEX} jmpq .*
+ \[paused\]
+ a.out`main \+ 63 at main.cpp:16
+ 11: {ADDRESS_REGEX} callq .* ; symbol stub for: foo\(\)
+ \[paused\]
+ a.out`main \+ 60 at main.cpp:14
+ 10: {ADDRESS_REGEX} movl .*
+ 9: {ADDRESS_REGEX} addl .*
+ 8: {ADDRESS_REGEX} movl .*
+ a.out`main \+ 52 \[inlined\] inline_function\(\) \+ 18 at main.cpp:6
+ 7: {ADDRESS_REGEX} movl .*
+ a.out`main \+ 49 \[inlined\] inline_function\(\) \+ 15 at main.cpp:5
+ 6: {ADDRESS_REGEX} movl .*
+ 5: {ADDRESS_REGEX} addl .*
+ 4: {ADDRESS_REGEX} movl .*
+ a.out`main \+ 34 \[inlined\] inline_function\(\) at main.cpp:4
+ 3: {ADDRESS_REGEX} movl .*
+ \[paused\]
+ a.out`main \+ 31 at main.cpp:12
+ 2: {ADDRESS_REGEX} movl .*
+ 1: {ADDRESS_REGEX} addl .*
+ \[paused\]
+ 0: {ADDRESS_REGEX} movl .*'''])
diff --git a/lldb/test/API/commands/trace/TestTraceLoad.py b/lldb/test/API/commands/trace/TestTraceLoad.py
index 47f7726f52824..731cade7587bc 100644
--- a/lldb/test/API/commands/trace/TestTraceLoad.py
+++ b/lldb/test/API/commands/trace/TestTraceLoad.py
@@ -40,12 +40,17 @@ def testLoadTrace(self):
Memory usage:
Raw trace size: 4 KiB
- Total approximate memory usage (excluding raw trace): 0.27 KiB
- Average memory usage per instruction (excluding raw trace): 13.00 bytes
+ Total approximate memory usage (excluding raw trace): 1.27 KiB
+ Average memory usage per instruction (excluding raw trace): 61.76 bytes
Timing:
Decoding instructions: ''', '''s
+ Events:
+ Number of instructions with events: 1
+ Number of individual events: 1
+ paused: 1
+
Errors:
Number of TSC decoding errors: 0'''])
More information about the lldb-commits
mailing list