This is an archive of the discontinued LLVM Phabricator instance.

[trace][intel pt] Support events
ClosedPublic

Authored by wallace on Apr 18 2022, 10:25 PM.

Details

Summary

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.

Diff Detail

Event Timeline

wallace created this revision.Apr 18 2022, 10:25 PM
Herald added a project: Restricted Project. · View Herald TranscriptApr 18 2022, 10:25 PM
wallace requested review of this revision.Apr 18 2022, 10:25 PM
Herald added a project: Restricted Project. · View Herald TranscriptApr 18 2022, 10:25 PM
wallace updated this revision to Diff 423535.Apr 18 2022, 10:35 PM

formatting

jj10306 added inline comments.Apr 19 2022, 5:26 AM
lldb/include/lldb/lldb-enumerations.h
1151

What are some other events you could forsee adding to this enum?

1155

Will this paused event always be due to a context switch? If so, we should rename it as such to reduce ambiguity

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

What is being "Set" and why have the extra layer of indirection with the private AppendError(Error &&e)? The name is a little confusing imo because all this does is call Append internally.
Any reason to not have AppendError public and call that directly?

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

What value does this providing the total number of instructions with events add? I think it could be more useful to provide a specific event as a parameter and return the total number of instructions with that particular event. wdyt?

258

I know this isn't related to these changes, but this should be updated to be consistent with the other instruction_index -> XXX maps in this class.

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

consider adding docs on insn being an "out" parameter so it's a little more clear

186

Why have the internal buffer overflow event as an error instead of a variant of the newly introduced Events enum?

lldb/test/API/commands/trace/TestTraceDumpInfo.py
52

Will this always be 1 or is there a possibility that it could be different depending on the number of context switches?

wallace added inline comments.Apr 19 2022, 7:54 AM
lldb/include/lldb/lldb-enumerations.h
1151

paging, execution mode change (from 64 to 32 bit mode or viceversa), power state change, core bus ratio change (i.e. frequency change). Some of these might include an additional payload, which should be gotten using other APIs.

1155

not really. Two examples:

  • context switch
  • ip filtering -> in this case tracing stopped at CPU level because an unwanted memory region was executed. In this case the process is still running
lldb/source/Plugins/Trace/intel-pt/DecodedThread.cpp
137

The reason is that I want all callers to invoke Append() except for exceptional cases. The benefit of Append is that can provide an error with events and timing information. SetAsFailed is receiving only an error without additional data to be used only in extreme situations where there's no event or timing data available, which happens if the decoding setup fails.

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

oh, i wanted to mean if and only if. Or is that too mathematical and less colloquial?

225

good idea

258

in this case we can't do that, because when doing random accesses in the trace, we need to quickly find the most recent TSC for the new instruction, which is done with binary search using a map. This is impossible in a hash map like DenseMap

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

good catch

186

that's because an overflow means that we lost data, and therefore we should show that as an error in the trace. Remember that errors mean that instructions were lost, which is exactly what happens in an overflow case. This is not just an event that could be ignored.

lldb/test/API/commands/trace/TestTraceDumpInfo.py
52

This is using trace load, which uses an offline trace, so it will never change.

wallace updated this revision to Diff 423654.Apr 19 2022, 9:28 AM

address comments. Still pending response about the iff word.

I've just created a stats objects for events with some util functions that make
the code much cleaner.

jj10306 added inline comments.Apr 20 2022, 4:44 AM
lldb/include/lldb/Target/TraceCursor.h
265

nit: maybe this will change in the future to where this will have data and instance members, but if not, consider just using a namespace here to house the utility functions since the class isn't really providing any state?

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

Lol my first thought actually was "I wonder if he meant if and only if, so this isn't a typo".
Up to you if you want to keep if or leave it as iff

258

I know this is a pedantic discussion, but isn't lookup in hash tables amortized O(1) (assuming a good hash that doesn't take too long to execute or produce the same hash for different values) whereas in an ordered map it's O(logn)?
IIUC, you should only use an ordered map when you rely on the order property of it.

In any case, we should use uint64_t here instead of size_t to be consistent with the type for instruction index used in the other maps.

wallace marked 13 inline comments as done.Apr 22 2022, 4:28 PM
wallace added inline comments.
lldb/include/lldb/Target/TraceCursor.h
265

great idea

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

i'll use if and only if

258

In any case, we should use uint64_t here instead of size_t to be consistent with the type for instruction index used in the other maps.

you are right with this one.

IIUC, you should only use an ordered map when you rely on the order property of it.

yes, and that's what we use for the timestamps. As there are a small number of unique timestamps, we are keeping this map 'insn_index -> timestamp'. We need its order property because when we do GoToId(insn_id) we need to look for most recent entry in the map that has a timestamp, and we use that timestamp for our new instruction. We use map.lower_bound for that. With a hashmap we couldn't do that.

wallace updated this revision to Diff 424658.Apr 22 2022, 4:31 PM
wallace marked 3 inline comments as done.

address comments

jj10306 accepted this revision.Apr 25 2022, 11:56 AM

Thanks for making those changes - lgtm!

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

We use map.lower_bound for that. With a hashmap we couldn't do that.

Ahhh yes, that makes sense - I forgot we were using that

This revision is now accepted and ready to land.Apr 25 2022, 11:56 AM