Skip to content

Commit 059f39d

Browse files
author
Walter Erquinigo
committed
[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
1 parent b0d119b commit 059f39d

17 files changed

+427
-111
lines changed

lldb/include/lldb/Target/TraceCursor.h

+32-1
Original file line numberDiff line numberDiff line change
@@ -234,9 +234,17 @@ class TraceCursor {
234234
/// \param[in] counter_type
235235
/// The counter type.
236236
/// \return
237-
/// The value of the counter or \b llvm::None if not available.
237+
/// The value of the counter or \b llvm::None if not available.
238238
virtual llvm::Optional<uint64_t> GetCounter(lldb::TraceCounter counter_type) = 0;
239239

240+
/// Get a bitmask with a list of events that happened chronologically right
241+
/// before the current instruction or error, but after the previous
242+
/// instruction.
243+
///
244+
/// \return
245+
/// The bitmask of events.
246+
virtual lldb::TraceEvents GetEvents() = 0;
247+
240248
/// \return
241249
/// The \a lldb::TraceInstructionControlFlowType categories the
242250
/// instruction the cursor is pointing at falls into. If the cursor points
@@ -254,6 +262,29 @@ class TraceCursor {
254262
bool m_forwards = false;
255263
};
256264

265+
namespace trace_event_utils {
266+
/// Convert an individual event to a display string.
267+
///
268+
/// \param[in] event
269+
/// An individual event.
270+
///
271+
/// \return
272+
/// A display string for that event, or nullptr if wrong data is passed
273+
/// in.
274+
const char *EventToDisplayString(lldb::TraceEvents event);
275+
276+
/// Invoke the given callback for each individual event of the given events
277+
/// bitmask.
278+
///
279+
/// \param[in] events
280+
/// A list of events to inspect.
281+
///
282+
/// \param[in] callback
283+
/// The callback to invoke for each event.
284+
void ForEachEvent(lldb::TraceEvents events,
285+
std::function<void(lldb::TraceEvents event)> callback);
286+
} // namespace trace_event_utils
287+
257288
} // namespace lldb_private
258289

259290
#endif // LLDB_TARGET_TRACE_CURSOR_H

lldb/include/lldb/Target/TraceInstructionDumper.h

+4
Original file line numberDiff line numberDiff line change
@@ -26,6 +26,8 @@ struct TraceInstructionDumperOptions {
2626
/// For each instruction, print the corresponding timestamp counter if
2727
/// available.
2828
bool show_tsc = false;
29+
/// Dump the events that happened between instructions.
30+
bool show_events = false;
2931
/// Optional custom id to start traversing from.
3032
llvm::Optional<uint64_t> id = llvm::None;
3133
/// Optional number of instructions to skip from the starting position
@@ -79,6 +81,8 @@ class TraceInstructionDumper {
7981
/// \b true if the cursor moved.
8082
bool TryMoveOneStep();
8183

84+
void PrintEvents();
85+
8286
lldb::TraceCursorUP m_cursor_up;
8387
TraceInstructionDumperOptions m_options;
8488
Stream &m_s;

lldb/include/lldb/lldb-enumerations.h

+9
Original file line numberDiff line numberDiff line change
@@ -1147,6 +1147,15 @@ enum TraceCounter {
11471147
eTraceCounterTSC,
11481148
};
11491149

1150+
// Events that might happen during a trace session.
1151+
FLAGS_ENUM(TraceEvents){
1152+
// Tracing was paused. If instructions were executed after pausing
1153+
// and before resuming, the TraceCursor used to traverse the trace
1154+
// should provide an error signalinig this data loss.
1155+
eTraceEventPaused = (1u << 0),
1156+
};
1157+
LLDB_MARK_AS_BITMASK_ENUM(TraceEvents)
1158+
11501159
} // namespace lldb
11511160

11521161
#endif // LLDB_LLDB_ENUMERATIONS_H

lldb/source/Commands/CommandObjectThread.cpp

+4
Original file line numberDiff line numberDiff line change
@@ -2156,6 +2156,10 @@ class CommandObjectTraceDumpInstructions : public CommandObjectParsed {
21562156
m_dumper_options.show_tsc = true;
21572157
break;
21582158
}
2159+
case 'e': {
2160+
m_dumper_options.show_events = true;
2161+
break;
2162+
}
21592163
case 'C': {
21602164
m_continue = true;
21612165
break;

lldb/source/Commands/Options.td

+7-4
Original file line numberDiff line numberDiff line change
@@ -1121,12 +1121,15 @@ let Command = "thread trace dump instructions" in {
11211121
def thread_trace_dump_instructions_show_tsc : Option<"tsc", "t">, Group<1>,
11221122
Desc<"For each instruction, print the corresponding timestamp counter if "
11231123
"available.">;
1124+
def thread_trace_dump_instructions_hide_events : Option<"events", "e">,
1125+
Group<1>,
1126+
Desc<"Dump the events that happened during the execution of the target.">;
11241127
def thread_trace_dump_instructions_continue: Option<"continue", "C">,
11251128
Group<1>,
1126-
Desc<"Continue dumping instructions right where the previous invocation of this "
1127-
"command was left, or from the beginning if this is the first invocation. The --skip "
1128-
"argument is discarded and the other arguments are preserved from the previous "
1129-
"invocation when possible.">;
1129+
Desc<"Continue dumping instructions right where the previous invocation of "
1130+
"this command was left, or from the beginning if this is the first "
1131+
"invocation. The --skip argument is discarded and the other arguments are "
1132+
"preserved from the previous invocation when possible.">;
11301133
}
11311134

11321135
let Command = "thread trace dump info" in {

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

+66-16
Original file line numberDiff line numberDiff line change
@@ -19,6 +19,18 @@ using namespace lldb_private;
1919
using namespace lldb_private::trace_intel_pt;
2020
using namespace llvm;
2121

22+
bool lldb_private::trace_intel_pt::IsLibiptError(int libipt_status) {
23+
return libipt_status < 0;
24+
}
25+
26+
bool lldb_private::trace_intel_pt::IsEndOfStream(int libipt_status) {
27+
return libipt_status == -pte_eos;
28+
}
29+
30+
bool lldb_private::trace_intel_pt::IsTscUnavailable(int libipt_status) {
31+
return libipt_status == -pte_no_time;
32+
}
33+
2234
char IntelPTError::ID;
2335

2436
IntelPTError::IntelPTError(int libipt_error_code, lldb::addr_t address)
@@ -35,6 +47,10 @@ void IntelPTError::log(llvm::raw_ostream &OS) const {
3547
OS << "error: " << libipt_error_message;
3648
}
3749

50+
DecodedInstruction::operator bool() const {
51+
return !IsLibiptError(libipt_error);
52+
}
53+
3854
size_t DecodedThread::GetInstructionsCount() const {
3955
return m_instruction_ips.size();
4056
}
@@ -93,15 +109,26 @@ void DecodedThread::RecordTscForLastInstruction(uint64_t tsc) {
93109
}
94110
}
95111

96-
void DecodedThread::AppendInstruction(const pt_insn &insn) {
97-
m_instruction_ips.emplace_back(insn.ip);
98-
m_instruction_sizes.emplace_back(insn.size);
99-
m_instruction_classes.emplace_back(insn.iclass);
100-
}
112+
void DecodedThread::Append(const DecodedInstruction &insn) {
113+
if (!insn) {
114+
// End of stream shouldn't be a public error
115+
if (IsEndOfStream(insn.libipt_error))
116+
return;
117+
118+
AppendError(make_error<IntelPTError>(insn.libipt_error, insn.pt_insn.ip));
119+
} else {
120+
m_instruction_ips.emplace_back(insn.pt_insn.ip);
121+
m_instruction_sizes.emplace_back(insn.pt_insn.size);
122+
m_instruction_classes.emplace_back(insn.pt_insn.iclass);
123+
}
101124

102-
void DecodedThread::AppendInstruction(const pt_insn &insn, uint64_t tsc) {
103-
AppendInstruction(insn);
104-
RecordTscForLastInstruction(tsc);
125+
if (insn.tsc)
126+
RecordTscForLastInstruction(*insn.tsc);
127+
128+
if (insn.events) {
129+
m_events.try_emplace(m_instruction_ips.size() - 1, insn.events);
130+
m_events_stats.RecordEventsForInstruction(insn.events);
131+
}
105132
}
106133

107134
void DecodedThread::AppendError(llvm::Error &&error) {
@@ -111,22 +138,45 @@ void DecodedThread::AppendError(llvm::Error &&error) {
111138
m_instruction_classes.emplace_back(pt_insn_class::ptic_error);
112139
}
113140

114-
void DecodedThread::AppendError(llvm::Error &&error, uint64_t tsc) {
141+
void DecodedThread::SetAsFailed(llvm::Error &&error) {
115142
AppendError(std::move(error));
116-
RecordTscForLastInstruction(tsc);
117143
}
118144

119-
void DecodedThread::LibiptErrors::RecordError(int libipt_error_code) {
120-
libipt_errors[pt_errstr(pt_errcode(libipt_error_code))]++;
145+
lldb::TraceEvents DecodedThread::GetEvents(int insn_index) {
146+
auto it = m_events.find(insn_index);
147+
if (it != m_events.end())
148+
return it->second;
149+
return (TraceEvents)0;
150+
}
151+
152+
void DecodedThread::LibiptErrorsStats::RecordError(int libipt_error_code) {
153+
libipt_errors_counts[pt_errstr(pt_errcode(libipt_error_code))]++;
121154
total_count++;
122155
}
123156

124157
void DecodedThread::RecordTscError(int libipt_error_code) {
125-
m_tsc_errors.RecordError(libipt_error_code);
158+
m_tsc_errors_stats.RecordError(libipt_error_code);
126159
}
127160

128-
const DecodedThread::LibiptErrors &DecodedThread::GetTscErrors() const {
129-
return m_tsc_errors;
161+
const DecodedThread::LibiptErrorsStats &
162+
DecodedThread::GetTscErrorsStats() const {
163+
return m_tsc_errors_stats;
164+
}
165+
166+
const DecodedThread::EventsStats &DecodedThread::GetEventsStats() const {
167+
return m_events_stats;
168+
}
169+
170+
void DecodedThread::EventsStats::RecordEventsForInstruction(
171+
lldb::TraceEvents events) {
172+
if (!events)
173+
return;
174+
175+
total_instructions_with_events++;
176+
trace_event_utils::ForEachEvent(events, [&](TraceEvents event) {
177+
events_counts[event]++;
178+
total_count++;
179+
});
130180
}
131181

132182
Optional<DecodedThread::TscRange> DecodedThread::CalculateTscRange(
@@ -187,7 +237,7 @@ size_t DecodedThread::CalculateApproximateMemoryUsage() const {
187237
sizeof(pt_insn::size) * m_instruction_sizes.size() +
188238
sizeof(pt_insn::iclass) * m_instruction_classes.size() +
189239
(sizeof(size_t) + sizeof(uint64_t)) * m_instruction_timestamps.size() +
190-
m_errors.getMemorySize();
240+
m_errors.getMemorySize() + m_events.getMemorySize();
191241
}
192242

193243
DecodedThread::TscRange::TscRange(std::map<size_t, uint64_t>::const_iterator it,

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

+75-23
Original file line numberDiff line numberDiff line change
@@ -23,6 +23,15 @@
2323
namespace lldb_private {
2424
namespace trace_intel_pt {
2525

26+
/// libipt status utils
27+
/// \{
28+
bool IsLibiptError(int libipt_status);
29+
30+
bool IsEndOfStream(int libipt_status);
31+
32+
bool IsTscUnavailable(int libipt_status);
33+
/// \}
34+
2635
/// Class for representing a libipt decoding error.
2736
class IntelPTError : public llvm::ErrorInfo<IntelPTError> {
2837
public:
@@ -51,6 +60,27 @@ class IntelPTError : public llvm::ErrorInfo<IntelPTError> {
5160
lldb::addr_t m_address;
5261
};
5362

63+
/// Helper struct for building an instruction or error from the decoder.
64+
/// It holds associated events and timing information.
65+
struct DecodedInstruction {
66+
DecodedInstruction() {
67+
pt_insn.ip = LLDB_INVALID_ADDRESS;
68+
libipt_error = pte_ok;
69+
}
70+
71+
DecodedInstruction(int libipt_error_code) : DecodedInstruction() {
72+
libipt_error = libipt_error_code;
73+
}
74+
75+
/// \return \b true if and only if this struct holds a libipt error.
76+
explicit operator bool() const;
77+
78+
int libipt_error;
79+
lldb::TraceEvents events = (lldb::TraceEvents)0;
80+
llvm::Optional<uint64_t> tsc = llvm::None;
81+
pt_insn pt_insn;
82+
};
83+
5484
/// \class DecodedThread
5585
/// Class holding the instructions and function call hierarchy obtained from
5686
/// 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> {
101131
};
102132

103133
// Struct holding counts for libipts errors;
104-
struct LibiptErrors {
134+
struct LibiptErrorsStats {
105135
// libipt error -> count
106-
llvm::DenseMap<const char *, int> libipt_errors;
107-
int total_count = 0;
136+
llvm::DenseMap<const char *, int> libipt_errors_counts;
137+
size_t total_count = 0;
108138

109139
void RecordError(int libipt_error_code);
110140
};
111141

142+
// Struct holding counts for events;
143+
struct EventsStats {
144+
/// A count for each individual event kind. We use an unordered map instead
145+
/// of a DenseMap because DenseMap can't understand enums.
146+
std::unordered_map<lldb::TraceEvents, size_t> events_counts;
147+
size_t total_count = 0;
148+
size_t total_instructions_with_events = 0;
149+
150+
void RecordEventsForInstruction(lldb::TraceEvents events);
151+
};
152+
112153
DecodedThread(lldb::ThreadSP thread_sp);
113154

114155
/// Utility constructor that initializes the trace with a provided error.
115156
DecodedThread(lldb::ThreadSP thread_sp, llvm::Error &&err);
116157

117-
/// Append a successfully decoded instruction.
118-
void AppendInstruction(const pt_insn &instruction);
158+
/// Append an instruction or a libipt error.
159+
void Append(const DecodedInstruction &insn);
119160

120-
/// Append a sucessfully decoded instruction with an associated TSC timestamp.
121-
void AppendInstruction(const pt_insn &instruction, uint64_t tsc);
122-
123-
/// Append a decoding error (i.e. an instruction that failed to be decoded).
124-
void AppendError(llvm::Error &&error);
161+
/// Append an error signaling that decoding completely failed.
162+
void SetAsFailed(llvm::Error &&error);
125163

126-
/// Append a decoding error with a corresponding TSC.
127-
void AppendError(llvm::Error &&error, uint64_t tsc);
164+
/// Get a bitmask with the events that happened chronologically right before
165+
/// the instruction pointed by the given instruction index, but after the
166+
/// previous instruction.
167+
lldb::TraceEvents GetEvents(int insn_index);
128168

129169
/// Get the total number of instruction pointers from the decoded trace.
130170
/// This will include instructions that indicate errors (or gaps) in the
@@ -175,13 +215,19 @@ class DecodedThread : public std::enable_shared_from_this<DecodedThread> {
175215
/// Get a new cursor for the decoded thread.
176216
lldb::TraceCursorUP GetCursor();
177217

178-
/// Return the number of TSC decoding errors that happened. A TSC error
179-
/// is not a fatal error and doesn't create gaps in the trace. Instead
180-
/// we only keep track of them as a statistic.
218+
/// Return an object with statistics of the TSC decoding errors that happened.
219+
/// A TSC error is not a fatal error and doesn't create gaps in the trace.
220+
/// Instead we only keep track of them as statistics.
181221
///
182222
/// \return
183-
/// The number of TSC decoding errors.
184-
const LibiptErrors &GetTscErrors() const;
223+
/// An object with the statistics of TSC decoding errors.
224+
const LibiptErrorsStats &GetTscErrorsStats() const;
225+
226+
/// Return an object with statistics of the trace events that happened.
227+
///
228+
/// \return
229+
/// The stats object of all the events.
230+
const EventsStats &GetEventsStats() const;
185231

186232
/// Record an error decoding a TSC timestamp.
187233
///
@@ -198,6 +244,9 @@ class DecodedThread : public std::enable_shared_from_this<DecodedThread> {
198244
lldb::ThreadSP GetThread();
199245

200246
private:
247+
/// Append a decoding error given an llvm::Error.
248+
void AppendError(llvm::Error &&error);
249+
201250
/// Notify this class that the last added instruction or error has
202251
/// an associated TSC.
203252
void RecordTscForLastInstruction(uint64_t tsc);
@@ -219,17 +268,20 @@ class DecodedThread : public std::enable_shared_from_this<DecodedThread> {
219268
/// are sporadic and we can think of them as ranges. If TSCs are present in
220269
/// the trace, all instructions will have an associated TSC, including the
221270
/// first one. Otherwise, this map will be empty.
222-
std::map<size_t, uint64_t> m_instruction_timestamps;
271+
std::map<uint64_t, uint64_t> m_instruction_timestamps;
223272
/// This is the chronologically last TSC that has been added.
224273
llvm::Optional<uint64_t> m_last_tsc = llvm::None;
225274
// This variables stores the messages of all the error instructions in the
226275
// trace. It maps `instruction index -> error message`.
227276
llvm::DenseMap<uint64_t, std::string> m_errors;
228-
/// The size in bytes of the raw buffer before decoding. It might be None if
229-
/// the decoding failed.
230-
llvm::Optional<size_t> m_raw_trace_size;
231-
/// All occurrences of libipt errors when decoding TSCs.
232-
LibiptErrors m_tsc_errors;
277+
/// This variable stores the bitmask of events that happened right before
278+
/// the instruction given as a key. It maps `instruction index -> events`.
279+
llvm::DenseMap<uint64_t, lldb::TraceEvents> m_events;
280+
281+
/// Statistics of all tracing events.
282+
EventsStats m_events_stats;
283+
/// Statistics of libipt errors when decoding TSCs.
284+
LibiptErrorsStats m_tsc_errors_stats;
233285
/// Total amount of time spent decoding.
234286
std::chrono::milliseconds m_total_decoding_time{0};
235287
};

0 commit comments

Comments
 (0)