Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

i#7050 remove preempted instruction and memref. #7058

Open
wants to merge 8 commits into
base: master
Choose a base branch
from
4 changes: 2 additions & 2 deletions clients/drcachesim/tests/offline-burst_aarch64_sys.templatex
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,7 @@ Total counts:
.* total data loads
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I looked back at the details and I really do not understand what is happening with this. Could you explain how this scenario occurred? I wrote some of my confusion at #7050 (comment).

Putting aside the fact that a regular asynch signal should not cause this kind of thing: if there were some real preempt from say thread relocation, why isn't raw2trace filling in the rest of the instructions in the block? How is the handler code running already? That makes it sound like raw2trace is already truncating the rest of the block and somehow solving #5790? On that note is this PR as written solving #5790?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What is in the raw trace records? What is the instruction count for the shl block? What is the exact raw trace order of the branch's block PC, shl block PC, shl address, and signal marker?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Here's the trace without the change:

        1436         982:       94080 ifetch       4 byte(s) @ 0x0000aaaae1534568 54000061   b.ne   $0x0000aaaae1534574 (untaken)
        1437         983:       94080 ifetch       4 byte(s) @ 0x0000aaaae153456c 97ffffbd   bl     $0x0000aaaae1534460 -> %x30
        1438         984:       94080 ifetch       4 byte(s) @ 0x0000aaaae1534460 a9be7bfd   stp    %x29 %x30 %sp $0xffffffffffffffe0 -> -0x20(%sp)[16byte] %sp
        1439         984:       94080 write       16 byte(s) @ 0x0000fffffb68e260 by PC 0x0000aaaae1534460
        1440         985:       94080 ifetch       4 byte(s) @ 0x0000aaaae1534464 910003fd   add    %sp $0x0000 lsl $0x00 -> %x29
        1441         986:       94080 ifetch       4 byte(s) @ 0x0000aaaae1534468 90001bc0   adrp   <rel> 0x0000aaaae18ac000 -> %x0
        1442         987:       94080 ifetch       4 byte(s) @ 0x0000aaaae153446c f944dc00   ldr    +0x09b8(%x0)[8byte] -> %x0
        1443         987:       94080 read         8 byte(s) @ 0x0000aaaae18ac9b8 by PC 0x0000aaaae153446c
        1444         988:       94080 ifetch       4 byte(s) @ 0x0000aaaae1534470 f9400001   ldr    (%x0)[8byte] -> %x1
        1445         988:       94080 read         8 byte(s) @ 0x0000fffeddbabb58 by PC 0x0000aaaae1534470
        1446         989:       94080 ifetch       4 byte(s) @ 0x0000aaaae1534474 f9000fe1   str    %x1 -> +0x18(%sp)[8byte]
        1447         989:       94080 write        8 byte(s) @ 0x0000fffffb68e278 by PC 0x0000aaaae1534474
        1448         990:       94080 ifetch       4 byte(s) @ 0x0000aaaae1534478 d2800001   movz   $0x0000 lsl $0x00 -> %x1
        1449         991:       94080 ifetch       4 byte(s) @ 0x0000aaaae153447c b90017ff   str    %wzr -> +0x14(%sp)[4byte]
        1450         991:       94080 write        4 byte(s) @ 0x0000fffffb68e274 by PC 0x0000aaaae153447c
        1451         992:       94080 ifetch       4 byte(s) @ 0x0000aaaae1534480 910053e0   add    %sp $0x0014 lsl $0x00 -> %x0
        1452         993:       94080 ifetch       4 byte(s) @ 0x0000aaaae1534484 d5087620   dc_ivac (%x0)[1byte]
        1453         993:       94080 dflush      64 byte(s) @ 0x0000fffffb68e274 by PC 0x0000aaaad5087620
        1454         993:       94080 <marker: kernel xfer from 0xaaaae1534484 to handler>
        1455         993:       94080 <marker: signal #4>
        1456         993:       94080 <marker: timestamp 13374886167543675>
        1457         993:       94080 <marker: tid 94080 on core 53>
        1458         994:       94080 ifetch       4 byte(s) @ 0x0000aaaae1534384 a9be7bfd   stp    %x29 %x30 %sp $0xffffffffffffffe0 -> -0x20(%sp)[16byte] %sp
        1459         994:       94080 write       16 byte(s) @ 0x0000fffffb68cff0 by PC 0x0000aaaae1534384

Raw trace:

0010c0 0000fffffb68e29c 0000fffffb68e29c
0010d0 200200000006456c 2024000000064460 1437         983:       94080 ifetch       4 byte(s) @ 0x0000aaaae153456c 97ffffbd bl     $0x0000aaaae1534460 -> %x30
                                         1438         984:       94080 ifetch       4 byte(s) @ 0x0000aaaae1534460 a9be7bfd stp    %x29 %x30 %sp $0xffffffffffffffe0 -> -0x20(%sp)[16byte] %sp
0010e0 0000fffffb68e260 0000aaaae18ac000
0010f0 0000fffeddbabb58 0000fffffb68e278
001100 0000fffffb68e274 0000fffffb68e274 1450         991:       94080 write        4 byte(s) @ 0x0000fffffb68e274 by PC 0x0000aaaae153447c
                                         1450         991:       94080 write        4 byte(s) @ 0x0000fffffb68e274 by PC 0x0000aaaae153447c
001110 c200aaaae1534484 c228000000000004 1454         993:       94080 <marker: kernel xfer from 0xaaaae1534484 to handler>
                                         1455         993:       94080 <marker: signal #4>
001120 802f84635aed7f7b c203000000000035
001130 2022000000064384 0000fffffb68cff0
001140 0000fffffb68d00c 0000aaaae18bde60
001150 0000aaaae18bde60 0000aaaae18bde60

.* total data stores
1 total icache flushes
4 total dcache flushes
3 total dcache flushes
1 total threads
.* total timestamp \+ cpuid markers
.*
Expand All @@ -25,6 +25,6 @@ Thread .* counts:
.* data loads
.* data stores
1 icache flushes
4 dcache flushes
3 dcache flushes
.* timestamp \+ cpuid markers
.*
20 changes: 10 additions & 10 deletions clients/drcachesim/tests/offline-legacy-int-offs.templatex
Original file line number Diff line number Diff line change
Expand Up @@ -3,12 +3,12 @@ ERROR: failed to initialize analyzer: Directory setup failed: Failed sanity chec
#elif defined(X86) && defined(X64)
Basic counts tool results:
Total counts:
109205 total \(fetched\) instructions
6768 total unique \(fetched\) instructions
109201 total \(fetched\) instructions
6765 total unique \(fetched\) instructions
93 total non-fetched instructions
11 total prefetches
23974 total data loads
5544 total data stores
23972 total data loads
5543 total data stores
0 total icache flushes
0 total dcache flushes
3 total threads
Expand All @@ -25,14 +25,14 @@ Total counts:
0 total system call number markers
0 total blocking system call markers
12 total other markers
8429 total encodings
8426 total encodings
Thread 552306 counts:
101049 \(fetched\) instructions
6393 unique \(fetched\) instructions
101045 \(fetched\) instructions
6390 unique \(fetched\) instructions
93 non-fetched instructions
11 prefetches
21712 data loads
4442 data stores
21710 data loads
4441 data stores
0 icache flushes
0 dcache flushes
110 timestamp \+ cpuid markers
Expand All @@ -48,7 +48,7 @@ Thread 552306 counts:
0 system call number markers
0 blocking system call markers
4 other markers
6393 encodings
6390 encodings
Thread 552323 counts:
4674 \(fetched\) instructions
1028 unique \(fetched\) instructions
Expand Down
126 changes: 123 additions & 3 deletions clients/drcachesim/tests/raw2trace_unit_tests.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -436,9 +436,10 @@ test_branch_delays(void *drcontext)
check_entry(entries, idx, TRACE_TYPE_MARKER, TRACE_MARKER_TYPE_FILETYPE) &&
check_entry(entries, idx, TRACE_TYPE_THREAD, -1) &&
check_entry(entries, idx, TRACE_TYPE_PID, -1) &&
check_entry(entries, idx, TRACE_TYPE_MARKER, TRACE_MARKER_TYPE_CACHE_LINE_SIZE) &&
check_entry(entries, idx, TRACE_TYPE_MARKER,
TRACE_MARKER_TYPE_CHUNK_INSTR_COUNT) &&
TRACE_MARKER_TYPE_CACHE_LINE_SIZE) && // 5 type: 28 size: 10 val: 64
check_entry(entries, idx, TRACE_TYPE_MARKER,
TRACE_MARKER_TYPE_CHUNK_INSTR_COUNT) && // 10000000
check_entry(entries, idx, TRACE_TYPE_MARKER, TRACE_MARKER_TYPE_TIMESTAMP) &&
check_entry(entries, idx, TRACE_TYPE_MARKER, TRACE_MARKER_TYPE_CPU_ID) &&
// Both branches should be delayed until after the timestamp+cpu markers:
Expand Down Expand Up @@ -3156,6 +3157,124 @@ test_ifiltered(void *drcontext)
#endif
}

/* Tests asynchronous signal handling (i#7050). */
bool
test_asynchronous_signal(void *drcontext)
{
bool res = true;
{
std::cerr << "\n===============\nTesting instr removal by async signal\n";
instrlist_t *ilist = instrlist_create(drcontext);
// raw2trace doesn't like offsets of 0 so we shift with a nop.
instr_t *nop = XINST_CREATE_nop(drcontext);
instr_t *move =
XINST_CREATE_move(drcontext, opnd_create_reg(REG1), opnd_create_reg(REG2));
instr_t *move2 =
XINST_CREATE_move(drcontext, opnd_create_reg(REG2), opnd_create_reg(REG1));
instrlist_append(ilist, nop);
instrlist_append(ilist, move);
instrlist_append(ilist, move2);
size_t offs_nop = 0;
size_t offs_move1 = offs_nop + instr_length(drcontext, nop);

std::vector<offline_entry_t> raw;
raw.push_back(make_header());
raw.push_back(make_tid());
raw.push_back(make_pid());
raw.push_back(make_line_size());
raw.push_back(make_timestamp());
raw.push_back(make_core());
raw.push_back(make_block(offs_move1, 1));
raw.push_back(make_marker(TRACE_MARKER_TYPE_KERNEL_EVENT, offs_move1));
raw.push_back(make_exit());

std::vector<uint64_t> stats;
std::vector<trace_entry_t> entries;
if (!run_raw2trace(drcontext, raw, ilist, entries, &stats))
return false;
int idx = 0;
res = check_entry(entries, idx, TRACE_TYPE_HEADER, -1) &&
check_entry(entries, idx, TRACE_TYPE_MARKER, TRACE_MARKER_TYPE_VERSION) &&
check_entry(entries, idx, TRACE_TYPE_MARKER, TRACE_MARKER_TYPE_FILETYPE) &&
check_entry(entries, idx, TRACE_TYPE_THREAD, -1) &&
check_entry(entries, idx, TRACE_TYPE_PID, -1) &&
check_entry(entries, idx, TRACE_TYPE_MARKER,
TRACE_MARKER_TYPE_CACHE_LINE_SIZE) &&
check_entry(entries, idx, TRACE_TYPE_MARKER,
TRACE_MARKER_TYPE_CHUNK_INSTR_COUNT) &&
check_entry(entries, idx, TRACE_TYPE_MARKER, TRACE_MARKER_TYPE_TIMESTAMP) &&
check_entry(entries, idx, TRACE_TYPE_MARKER, TRACE_MARKER_TYPE_CPU_ID) &&
// The move instruction is removed because of the asynchronous signal.
check_entry(entries, idx, TRACE_TYPE_MARKER, TRACE_MARKER_TYPE_KERNEL_EVENT,
offs_move1) &&
check_entry(entries, idx, TRACE_TYPE_THREAD_EXIT, -1) &&
check_entry(entries, idx, TRACE_TYPE_FOOTER, -1);
}
{
std::cerr
<< "\n===============\nTesting instr and memref removal by async signal\n";
instrlist_t *ilist = instrlist_create(drcontext);
// raw2trace doesn't like offsets of 0 so we shift with a nop.
instr_t *nop = XINST_CREATE_nop(drcontext);
instr_t *move =
XINST_CREATE_move(drcontext, opnd_create_reg(REG1), opnd_create_reg(REG2));
instr_t *store = XINST_CREATE_store(drcontext, OPND_CREATE_MEMPTR(REG2, 0),
opnd_create_reg(REG1));
instr_t *move2 =
XINST_CREATE_move(drcontext, opnd_create_reg(REG2), opnd_create_reg(REG1));
instrlist_append(ilist, nop);
instrlist_append(ilist, move);
instrlist_append(ilist, store);
instrlist_append(ilist, move2);
size_t offs_nop = 0;
size_t offs_move1 = offs_nop + instr_length(drcontext, nop);
size_t offs_store = offs_move1 + instr_length(drcontext, move);
size_t offs_move2 = offs_store + instr_length(drcontext, store);

std::vector<offline_entry_t> raw;
raw.push_back(make_header());
raw.push_back(make_tid());
raw.push_back(make_pid());
raw.push_back(make_line_size());
raw.push_back(make_timestamp());
raw.push_back(make_core());
raw.push_back(make_block(offs_move1, 2));
raw.push_back(make_memref(42));
raw.push_back(make_marker(TRACE_MARKER_TYPE_KERNEL_EVENT, offs_store));
raw.push_back(make_block(offs_move2, 1));
raw.push_back(make_exit());

std::vector<uint64_t> stats;
std::vector<trace_entry_t> entries;
if (!run_raw2trace(drcontext, raw, ilist, entries, &stats))
return false;
int idx = 0;
res &=
(check_entry(entries, idx, TRACE_TYPE_HEADER, -1) &&
check_entry(entries, idx, TRACE_TYPE_MARKER, TRACE_MARKER_TYPE_VERSION) &&
check_entry(entries, idx, TRACE_TYPE_MARKER, TRACE_MARKER_TYPE_FILETYPE) &&
check_entry(entries, idx, TRACE_TYPE_THREAD, -1) &&
check_entry(entries, idx, TRACE_TYPE_PID, -1) &&
check_entry(entries, idx, TRACE_TYPE_MARKER,
TRACE_MARKER_TYPE_CACHE_LINE_SIZE) &&
check_entry(entries, idx, TRACE_TYPE_MARKER,
TRACE_MARKER_TYPE_CHUNK_INSTR_COUNT) &&
check_entry(entries, idx, TRACE_TYPE_MARKER, TRACE_MARKER_TYPE_TIMESTAMP) &&
check_entry(entries, idx, TRACE_TYPE_MARKER, TRACE_MARKER_TYPE_CPU_ID) &&
// The move instruction.
check_entry(entries, idx, TRACE_TYPE_ENCODING, -1) &&
check_entry(entries, idx, TRACE_TYPE_INSTR, -1, offs_move1) &&
// The store instruction and the memref are removed.
check_entry(entries, idx, TRACE_TYPE_MARKER, TRACE_MARKER_TYPE_KERNEL_EVENT,
offs_store) &&
check_entry(entries, idx, TRACE_TYPE_ENCODING, -1) &&
check_entry(entries, idx, TRACE_TYPE_INSTR, -1, offs_move2) &&
check_entry(entries, idx, TRACE_TYPE_THREAD_EXIT, -1) &&
check_entry(entries, idx, TRACE_TYPE_FOOTER, -1));
}
return res;
}

int
test_main(int argc, const char *argv[])
{
Expand All @@ -3177,7 +3296,8 @@ test_main(int argc, const char *argv[])
!test_xfer_modoffs(drcontext) || !test_xfer_absolute(drcontext) ||
!test_branch_decoration(drcontext) ||
!test_stats_timestamp_instr_count(drcontext) ||
!test_is_maybe_blocking_syscall(drcontext) || !test_ifiltered(drcontext))
!test_is_maybe_blocking_syscall(drcontext) || !test_ifiltered(drcontext) ||
!test_asynchronous_signal(drcontext))
return 1;
return 0;
}
Expand Down
24 changes: 16 additions & 8 deletions clients/drcachesim/tests/signal_invariants.c
Original file line number Diff line number Diff line change
Expand Up @@ -190,8 +190,10 @@ GLOBAL_LABEL(FUNCNAME:)
#define FUNCNAME test_signal_midbb
DECLARE_FUNC(FUNCNAME)
GLOBAL_LABEL(FUNCNAME:)
/* prefetcht2's address is the instr count until a signal */
prefetcht2 [3]
/* prefetcht2's address is the instr count until a signal not counting
* the preempted instr.
*/
prefetcht2 [2]
nop
nop
ud2
Expand All @@ -205,8 +207,10 @@ GLOBAL_LABEL(FUNCNAME:)
#define FUNCNAME test_signal_startbb
DECLARE_FUNC(FUNCNAME)
GLOBAL_LABEL(FUNCNAME:)
/* prefetcht2's address is the instr count until a signal */
prefetcht2 [2]
/* prefetcht2's address is the instr count until a signal not counting
* the preempted instr.
*/
prefetcht2 [1]
jmp new_bb
new_bb:
ud2
Expand All @@ -221,10 +225,14 @@ GLOBAL_LABEL(FUNCNAME:)
* XXX i#3958: Today the 2nd movs memref is incorrectly included *before*
* the fault.
*/
/* prefetcht2's address is the instr count until a signal */
prefetcht2 [5]
/* prefetcht1's address is the memref count until a signal */
prefetcht1 [3]
/* prefetcht2's address is the instr count until a signal not counting
* the preempted instr.
*/
prefetcht2 [4]
/* prefetcht1's address is the memref count until a signal not counting
* the preempted memref.
*/
prefetcht1 [1]
mov REG_XSI, HEX(42)
mov REG_XDI, REG_XSP
push REG_XAX
Expand Down
Loading
Loading