Skip to content

Commit

Permalink
Update traces with kernel interruption entries
Browse files Browse the repository at this point in the history
Re-generates both the x86_64 and aarch64 traces to include the new
kernel interruption PC entries.

Updates the README files to match the new trace details.
Updates the libraries in the binaries directories.
Updates the verbose listings to use the "view" tool, since
it now includes loads and stores.

Fixes: DynamoRIO/dynamorio#4274
  • Loading branch information
derekbruening committed Jul 8, 2021
1 parent 980f651 commit a8c9d48
Show file tree
Hide file tree
Showing 97 changed files with 227 additions and 140 deletions.
92 changes: 63 additions & 29 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -23,39 +23,73 @@ file](https://github.com/DynamoRIO/dynamorio/blob/master/clients/drcachesim/comm
A simple analysis tool to look at is
[basic_counts.cpp](https://github.com/DynamoRIO/dynamorio/blob/master/clients/drcachesim/tools/basic_counts.cpp).

A low-level textual view of a sample trace:

A human-readable view of a sample trace highlighting thread switches and
a signal handler:
```
$ bin64/drrun -t drcachesim -indir drmemtrace*.dir -verbose 3 2>&1 | less
::142994.142994:: marker type 2 value 13214166611094895
::142994.142994:: marker type 3 value 0
new thread 142994 => core 0 (count=0)
::142994.142994:: @0x7fa4ca039f30 instr x3
::142994.142994:: @0x7fa4ca039f33 instr x5
::142994.142994:: @0x7fa4ca039f33 write 0x7fffb0db9b28 x8
::142994.142994:: @0x7fa4ca03ad30 instr x1
::142994.142994:: @0x7fa4ca03ad30 write 0x7fffb0db9b20 x8
::142994.142994:: @0x7fa4ca03ad31 instr x3
...
::142994.142994:: @0x7fa4c8afcddf instr x2
::142994.142995:: marker type 2 value 13214166611281895
::142994.142995:: marker type 3 value 3
new thread 142995 => core 1 (count=0)
::142994.142995:: @0x7fa4c8afcde1 instr x3
::142994.142995:: @0x7fa4c8afcde4 instr x2
::142994.142995:: marker type 0 value 0
::142994.142995:: marker type 2 value 13214166611282372
::142994.142995:: marker type 3 value 3
::142994.142995:: @0x7fa4c8afcde6 instr x2
::142994.142995:: @0x7fa4c605edba instr x1
::142994.142995:: @0x7fa4c605edba write 0x7fa4c89fd8e0 x8
...
$ bin64/drrun -t drcachesim -indir drmemtrace.threadsig.[0-9]*.dir -simulator_type view 2>&1 | less
<...>
T468608 0x0000000000467c45 4c 8b 54 24 08 mov 0x08(%rsp), %r10
T468608 read 8 byte(s) @ 0x7fff9f5fd9b0
T468608 0x0000000000467c4a b8 38 00 00 00 mov $0x00000038, %eax
T468608 0x0000000000467c4f 0f 05 syscall
------------------------------------------------------------
T468610 <marker: timestamp 13270239527782712>
T468610 <marker: tid 468610 on core 0>
T468610 0x0000000000467c51 48 85 c0 test %rax, %rax
T468610 0x0000000000467c54 7c 13 jl $0x0000000000467c69
T468610 0x0000000000467c56 74 01 jz $0x0000000000467c59
T468610 0x0000000000467c59 31 ed xor %ebp, %ebp
T468610 0x0000000000467c5b 58 pop %rax
T468610 read 8 byte(s) @ 0x7f669dc77e70
T468610 0x0000000000467c5c 5f pop %rdi
T468610 read 8 byte(s) @ 0x7f669dc77e78
T468610 0x0000000000467c5d ff d0 call %rax
<...>
T468608 0x0000000000405376 64 c7 04 25 18 00 00 movl $0x00000001, %fs:0x18
T468608 00 01 00 00 00
T468608 write 4 byte(s) @ 0x4eb898
T468608 0x0000000000405382 45 31 c0 xor %r8d, %r8d
T468608 0x0000000000405385 eb 2f jmp $0x00000000004053b6
T468608 <marker: kernel xfer from 0x4053b6 to handler>
T468608 <marker: timestamp 13270239527784929>
T468608 <marker: tid 468608 on core 2>
T468608 0x000000000040257d 55 push %rbp
T468608 write 8 byte(s) @ 0x7fff9f5fd330
T468608 0x000000000040257e 48 89 e5 mov %rsp, %rbp
T468608 0x0000000000402581 89 7d fc mov %edi, -0x04(%rbp)
T468608 write 4 byte(s) @ 0x7fff9f5fd32c
T468608 0x0000000000402584 48 89 75 f0 mov %rsi, -0x10(%rbp)
T468608 write 8 byte(s) @ 0x7fff9f5fd320
T468608 0x0000000000402588 48 89 55 e8 mov %rdx, -0x18(%rbp)
T468608 write 8 byte(s) @ 0x7fff9f5fd318
T468608 0x000000000040258c 83 7d fc 1a cmp -0x04(%rbp), $0x1a
T468608 read 4 byte(s) @ 0x7fff9f5fd32c
T468608 0x0000000000402590 75 0f jnz $0x00000000004025a1
T468608 0x0000000000402592 8b 05 5c 0f 0e 00 mov <rel> 0x00000000004e34f4, %eax
T468608 read 4 byte(s) @ 0x4e34f4
T468608 0x0000000000402598 83 c0 01 add $0x01, %eax
T468608 0x000000000040259b 89 05 53 0f 0e 00 mov %eax, <rel> 0x00000000004e34f4
T468608 write 4 byte(s) @ 0x4e34f4
T468608 0x00000000004025a1 90 nop
T468608 0x00000000004025a2 5d pop %rbp
T468608 read 8 byte(s) @ 0x7fff9f5fd330
T468608 0x00000000004025a3 c3 ret
T468608 read 8 byte(s) @ 0x7fff9f5fd338
T468608 0x0000000000407bb0 48 c7 c0 0f 00 00 00 mov $0x0000000f, %rax
T468608 0x0000000000407bb7 0f 05 syscall
T468608 <marker: timestamp 13270239527784936>
T468608 <marker: tid 468608 on core 2>
T468608 <marker: syscall xfer from 0x407bb9>
T468608 <marker: timestamp 13270239527792923>
T468608 <marker: tid 468608 on core 2>
T468608 0x00000000004053b6 80 bd 7c ff ff ff 00 cmp -0x84(%rbp), $0x00
T468608 read 1 byte(s) @ 0x7fff9f5fda4c
<...>
```

It is a series of instruction fetch, data fetch, and metadata entries. The
fetches contain addresses and sizes ("x3" is a size in the verbose
listing). The addresses are all virtual (it is possible to [gather
physical addresses in some
fetches contain addresses and sizes. The addresses are all virtual
(it is possible to [gather physical addresses in some
circumstances](https://dynamorio.org/sec_drcachesim_phys.html)).
The metadata "markers" indicate things like which core a thread executed
on, timestamps, an arriving signal causing a PC discontinuity, etc.
Expand Down
140 changes: 80 additions & 60 deletions threadsig.aarch64/README.txt
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
Sample aarch64 trace directory contents:
+ drmemtrace.threadsig.49768.5624.dir/trace/* == the trace itself, with a
+ drmemtrace.threadsig.1287316.5396.dir/trace/* == the trace itself, with a
separate file per application thread.
+ drmemtrace.threadsig.49768.5624.dir/raw/modules.log == the list of libraries
+ drmemtrace.threadsig.1287316.5396.dir/raw/modules.log == the list of libraries
mapped into the application address space.
+ binaries/ == binaries for the librares listed in the modules.log file.
+ threadsig.cpp == the source code of the traced application.
Expand All @@ -14,50 +14,70 @@ framework [2].
The trace format used by analysis tools is the memref_t structure [3]. A
simple analysis tool to look at is basic_counts.cpp [4].

A low-level textual view of the sample trace:
A human-readable view of the sample trace highlighting thread switches and
a signal handler:
--------------------------------------------------
$ bin64/drrun -t drcachesim -indir drmemtrace*.dir -verbose 3 2>&1 | less
::49768.49768:: marker type 2 value 13260902406616557
::49768.49768:: marker type 3 value 42
new thread 49768 => core 0 (count=0)
::49768.49768:: @0x400678 instr x4
::49768.49768:: @0x40067c instr x4
::49768.49768:: @0x400680 instr x4
::49768.49768:: @0x400684 instr x4
::49768.49768:: @0x400684 read 0xfffffe05ecc0 x8
::49768.49768:: @0x400688 instr x4
$ bin64/drrun -t drcachesim -indir drmemtrace.threadsig.[0-9]*.dir -simulator_type view 2>&1 | less
<...>
::49768.49768:: @0x42d170 instr x4
::49768.49768:: @0x42d174 instr x4
::49768.49768:: @0x42d178 instr x4
::49768.49769:: marker type 2 value 13260902407398488
::49768.49769:: marker type 3 value 50
::49768.49769:: marker type 0 value 189040
::49768.49769:: marker type 2 value 13260902407398716
::49768.49769:: marker type 3 value 50
new thread 49769 => core 1 (count=0)
::49768.49769:: @0x4008d8 instr x4
::49768.49769:: @0x4008dc instr x4
::49768.49769:: @0x4008e0 instr x4
::49768.49769:: @0x4008e4 instr x4
::49768.49769:: @0x4008e8 instr x4
::49768.49769:: @0x4008e8 read 0x4a7ab8 x4
::49768.49769:: @0x4008ec instr x4
::49768.49769:: @0x4008f0 instr x4
::49768.49769:: @0x4008f0 write 0x4a7ab8 x4
T1287316 0x000000007132b464 52801168 movz $0x008b lsl $0x00 -> %w8
T1287316 0x000000007132b468 d4000001 svc $0x0000
T1287316 <marker: timestamp 13270240897157787>
T1287316 <marker: tid 1287316 on core 29>
T1287316 <marker: syscall xfer from 0x7132b46c>
------------------------------------------------------------
T1287317 <marker: timestamp 13270240897161378>
T1287317 <marker: tid 1287317 on core 30>
T1287317 0x000000000042e270 f100001f subs %x0 $0x0000 lsl $0x00 -> %xzr
T1287317 0x000000000042e274 540000e0 b.eq $0x000000000042e290
T1287317 0x000000000042e290 d280001d movz $0x0000 lsl $0x00 -> %x29
T1287317 0x000000000042e294 aa0c03e0 orr %xzr %x12 lsl $0x00 -> %x0
T1287317 0x000000000042e298 d63f0140 blr %x10 -> %x30
T1287317 0x0000000000401d10 a9ae7bfd stp %x29 %x30 %sp $0xfffffffffffffee0 -> -0x0120(%sp)[16byte] %sp
T1287317 write 16 byte(s) @ 0xfffda57f6880
<...>
T1287316 0x0000000000400b28 a9425bf5 ldp +0x20(%sp)[16byte] -> %x21 %x22
T1287316 read 16 byte(s) @ 0xffffd79a6f50
T1287316 0x0000000000400b2c a8c57bfd ldp (%sp)[16byte] %sp $0x0000000000000050 -> %x29 %x30 %sp
T1287316 read 16 byte(s) @ 0xffffd79a6f30
T1287316 0x0000000000400b30 d65f03c0 ret %x30
T1287316 <marker: kernel xfer from 0x4023dc to handler>
T1287316 <marker: timestamp 13270240897161609>
T1287316 <marker: tid 1287316 on core 29>
T1287316 0x00000000004008d8 7100681f subs %w0 $0x001a lsl $0x00 -> %wzr
T1287316 0x00000000004008dc 540000c1 b.ne $0x00000000004008f4
T1287316 0x00000000004008e0 f0000520 adrp <rel> 0x00000000004a7000 -> %x0
T1287316 0x00000000004008e4 9129c000 add %x0 $0x0a70 lsl $0x00 -> %x0
T1287316 0x00000000004008e8 b9404801 ldr +0x48(%x0)[4byte] -> %w1
T1287316 read 4 byte(s) @ 0x4a7ab8
T1287316 0x00000000004008ec 11000421 add %w1 $0x0001 lsl $0x00 -> %w1
T1287316 0x00000000004008f0 b9004801 str %w1 -> +0x48(%x0)[4byte]
T1287316 write 4 byte(s) @ 0x4a7ab8
T1287316 0x00000000004008f4 d65f03c0 ret %x30
T1287316 0x000000007132b464 52801168 movz $0x008b lsl $0x00 -> %w8
T1287316 0x000000007132b468 d4000001 svc $0x0000
T1287316 <marker: timestamp 13270240897161623>
T1287316 <marker: tid 1287316 on core 29>
T1287316 <marker: syscall xfer from 0x7132b46c>
T1287316 <marker: timestamp 13270240897165865>
T1287316 <marker: tid 1287316 on core 29>
T1287316 0x00000000004023dc 2a0003e4 orr %wzr %w0 lsl $0x00 -> %w4
T1287316 0x00000000004023e0 35003280 cbnz $0x0000000000402a30 %w0
T1287316 0x00000000004023e4 39504f80 ldrb +0x0413(%x28)[1byte] -> %w0
T1287316 read 1 byte(s) @ 0xfffda5c9a413
T1287316 0x00000000004023e8 35000e40 cbnz $0x00000000004025b0 %w0
<...>
--------------------------------------------------

It is a series of instruction fetch, data fetch, and metadata entries. The
fetches contain addresses and sizes ("x4" is a size in the verbose
listing). The addresses are all virtual. The metadata
fetches contain addresses and sizes. The addresses are all virtual. The metadata
"markers" indicate things like which core a thread executed on, timestamps,
an arriving signal causing a PC discontinuity, etc.

For using a trace in a core simulator, you will want to obtain the opcodes.
For using a trace in a core simulator, you will want to obtain the opcodes,
as is done with the "view" tool above.
These are not part of the base trace. They are obtained by decoding the
instruction fetch addresses from the binaries. Library support makes this
straightforward. A sample tool that does this is opcode_mix.cpp [5]. It
straightforward. A simple tool that does this is opcode_mix.cpp [5]. It
uses library routines to read the "modules.log" file, which contains the
mappings of the binary and libraries from the traced execution, and map
those binaries into the address space, allowing examining the instruction
Expand All @@ -78,48 +98,48 @@ The trace was generated by running:
$ bin64/drrun -t drcachesim -offline -- ./threadsig 20 200000

Counts of event types in the trace:
$ bin64/drrun -t drcachesim -indir drmemtrace*.dir -simulator_type basic_counts
Basic counts tool results:
Total counts:
10651975 total (fetched) instructions
6399 total unique (fetched) instructions
$ bin64/drrun -t drcachesim -indir drmemtrace.threadsig.[0-9]*.dir -simulator_type basic_counts
Basic counts tool results:
Total counts:
12050396 total (fetched) instructions
6401 total unique (fetched) instructions
0 total non-fetched instructions
39 total prefetches
210300 total data loads
2207422 total data stores
210224 total data loads
2607266 total data stores
0 total icache flushes
0 total dcache flushes
21 total threads
3436 total scheduling markers
484 total transfer markers
2738 total scheduling markers
90 total transfer markers
0 total function id markers
0 total function return address markers
0 total function argument markers
0 total function return value markers
42 total other markers
Thread 49770 counts:
530374 (fetched) instructions
375 unique (fetched) instructions
63 total other markers
Thread 1287317 counts:
600344 (fetched) instructions
374 unique (fetched) instructions
<...>

Top opcodes in the trace:
$ bin64/drrun -t drcachesim -indir drmemtrace*.dir -simulator_type opcode_mix -module_file drmemtrace*.dir/raw/modules.log
$ bin64/drrun -t drcachesim -indir drmemtrace.threadsig.[0-9]*.dir -simulator_type opcode_mix -module_file drmemtrace.threadsig.[0-9]*.dir/raw/modules.log
Opcode mix tool results:
10651975 : total executed instructions
1404641 : bcond
12050396 : total executed instructions
1604491 : bcond
1405742 : add
1403710 : subs
1403183 : stp
1203860 : subs
1006120 : add
800679 : and
600116 : xx
403529 : str
401986 : movz
800681 : and
800039 : sys
403334 : str
401790 : movz
<...>

The "xx" is part of a set of opcodes not yet added to the decoder [8].
(If the opcode "xx" is displayed, it is part of a set of opcodes not yet
added to the decoder [8].)

You can run any of the commands above yourself by downloading DynamoRIO
[9].
You can run any of the commands above yourself by downloading DynamoRIO [9].

References from above:

Expand Down
Binary file modified threadsig.aarch64/binaries/libdrmemtrace.so
Binary file not shown.
Binary file modified threadsig.aarch64/binaries/libdynamorio.so
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Binary file not shown.
Loading

0 comments on commit a8c9d48

Please sign in to comment.