DynamoRIO / DynamoRIO/dynamorio

Multiple problems with same-file drmemtrace windows: double footer and kernel marker on wrong side of window

Open
#6,228 0 comments 0 reactions 0 assignees View on GitHub
Component-DrMemtrace
Dominant language
C
Stars
3.2k
Forks
629
Avg merge
2d 15h
Merged PRs (30d)
31

Description

As part of #6213 where I remove a branch at the end of a window I tested windows more aggressively than the suite test by running threadsig (see https://github.com/DynamoRIO/drmemtrace_samples):

```
rm -rf drmemtrace.*.dir; bin64/drrun -stderr_mask 12 -t drcachesim -offline -max_trace_size 20M -no_split_windows -trace_after_instrs 20K -trace_for_instrs 4K -retrace_every_instrs 35K -- ~/dr/test/threadsig 4 2000; bin64/drrun -t drcachesim -indir drmemtrace.*.dir -simulator_type invariant_checker
```

I hit two different issues.

First, in one run (didn't reproduce later), I hit a double footer:
```
$ rm -rf /tmp/foo/*; clients/bin64/drraw2trace -indir drmemtrace.*.dir -out /tmp/foo -verbose 4 -jobs 0
<...>
[drmemtrace]: Appending 2 instrs in bb 0x7f14fdf11c98 in mod 19 +0x9ac98 = /usr/lib/x86_64-linux-gnu/libc.so.6
0x00007f96f66b9c98 48 83 c4 08 add $0x0000000000000008 %rsp -> %rsp
[drmemtrace]: Appending delayed branch tagalong entry type read (0) for thread 3
[drmemtrace]: Inserted indirect branch target 0x7f96f66b9c98
[drmemtrace]: Appending delayed branch type=16 pc=0x7f96f66a45a9 decode=0x7f14fdefc5a9 target=(nil) for thread 3
[drmemtrace]: Appending delayed branch tagalong entry type encoding (47) for thread 3
[drmemtrace]: Chunk instr count is now 12890
[drmemtrace]: Appended encoding entry for 0x7f14fdf11c98 sz=4 0x08c48348...
[drmemtrace]: Appended instr fetch for original 0x7f96f66b9c98
[drmemtrace]: Chunk instr count is now 12891
0x00007f96f66b9c9c e9 2f e1 ff ff jmp $0x00007f96f66b7dd0
[drmemtrace]: Appended encoding entry for 0x7f14fdf11c9c sz=5 0xffe12fe9...
[drmemtrace]: Appended instr fetch for original 0x7f96f66b9c9c
[drmemtrace]: Delaying 2 entries for decode=0x7f14fdf11c9c
[drmemtrace]: Remembered delayed branch decode=0x7f14fdf11c9c target=0x7f96f66b7dd0
[drmemtrace]: Appending delayed branch type=11 pc=0x7f96f66b9c9c decode=0x7f14fdf11c9c target=0x7f96f66b7dd0 for thread 3
[drmemtrace]: Appending delayed branch tagalong entry type encoding (47) for thread 3
[drmemtrace]: Chunk instr count is now 12892
[drmemtrace]: Thread 2484314 exit
[drmemtrace]: Chunk instr count is now 12892
ERROR: Conversion failed: Failed to process file for thread 2484314: Footer is not the final entry
```

The raw file has two footers:
```
$ unlz4 -c drmemtrace.*.dir/raw/*2484314* | od -t x8 -A x | tail
04b400 200a002600085570 00007f96f5e1cec8
04b410 00007f96f5e1d650 20040026000855a8
04b420 00007f96f5e1cec0 00007f96f5e1cec8
04b430 200400260009ac98 c100000000000000
04b440 802f5fdc3593d625 c20e00000000002e
04b450 c203000000000000 c100000000000000
04b460
```

Second, I hit, in multiple runs, a kernel event marker right before a window end which looks like it should be *after* the window end and at the start of the next window:
```
Trace invariant failure in T2491864 at ref # 462318: Branch does not go to the correct target

$ bin64/drrun -t drcachesim -simulator_type view -indir drmemtrace.*.dir -only_thread 2491864 -skip_refs 462310 -sim_refs 20
462315 343801: 2491864 ifetch 3 byte(s) @ 0x00007fd1ed9fab61 48 89 c7 mov %rax, %rdi
462316 343802: 2491864 ifetch 5 byte(s) @ 0x00007fd1ed9fab64 e8 bb fe ff ff call $0x00007fd1ed9faa24
462317 343802: 2491864 write 8 byte(s) @ 0x00007ffdd70645f8 by PC 0x00007fd1ed9fab64
462318 343802: 2491864
------------------------------------------------------------
------------------------------------------------------------
462320 343802: 2491864
462320 343802: 2491864
462320 343802: 2491864 462321 343802: 2491864
462322 343803: 2491864 ifetch 1 byte(s) @ 0x00007fd1ed9fa259 55 push %rbp
462323 343803: 2491864 write 8 byte(s) @ 0x00007ffdd7063840 by PC 0x
<...>
462345 343816: 2491864 ifetch 7 byte(s) @ 0x00007fd1f0e5af90 48 c7 c0 0f 00 00 00 mov $0x0000000f, %rax
462346 343817: 2491864 ifetch 2 byte(s) @ 0x00007fd1f0e5af97 0f 05 syscall
462347 343817: 2491864

------------------------------------------------------------
462349 343817: 2491864
462349 343817: 2491864 462350 343817: 2491864
462351 343817: 2491864

------------------------------------------------------------
462353 343817: 2491864
462353 343817: 2491864 462354 343817: 2491864
462355 343818: 2491864 ifetch 4 byte(s) @ 0x00007fd1ed9fb0a0 48 8b 45 f8 mov -0x08(%rbp), %rax
```

Since same-file windows aren't a main focus for us I'm not going to spend time on this now; filing for future work.

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.