Skip to content

i#3995 irregular window tracing: last window bug fix #7448

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

Open
wants to merge 7 commits into
base: master
Choose a base branch
from
Open
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
23 changes: 19 additions & 4 deletions clients/drcachesim/tracer/instr_counter.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -41,6 +41,7 @@
#include <stddef.h>
Copy link
Contributor

Choose a reason for hiding this comment

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

Before submitting, maybe we should test this on a large app to make sure everything is WAI.

#include <atomic>
#include <cstdint>
#include <inttypes.h>

// These libraries are safe to use during initialization only.
// See api/docs/deployment.dox sec_static_DR.
Expand Down Expand Up @@ -156,6 +157,8 @@ get_current_no_trace_for_instrs_value()
return 0;
}

// This function returns true if, at the current no-trace window, there exists an
// instruction count threshold to enable tracing.
static bool
has_instr_count_threshold_to_enable_tracing()
{
Expand Down Expand Up @@ -470,6 +473,13 @@ parse_instr_intervals_file(std::string path_to_file)
if (!std::getline(ss, elem, ','))
FATAL("Fatal error: instruction duration not found.\n");
uint64 duration = std::stoull(elem);
if (duration == 0) {
NOTIFY(0,
"Instruction interval starting at %" PRIu64 " has duration of 0. "
"Removing interval.\n",
start);
continue;
Copy link
Contributor Author

@edeiana edeiana May 2, 2025

Choose a reason for hiding this comment

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

The main changes from the last review are:

  1. Using UINT64_MAX instead of 0 for the last "no trace" window we add.
  2. Added a NOTIFY message if the user-defined instruction intervals contain intervals of duration == 0 (we skip it).
  3. Added a NOTIFY message when we merge overlapping intervals.

Copy link
Contributor

Choose a reason for hiding this comment

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

Please update the PR description.

}
// Ignore the remaining comma-separated elements, if any.

instr_intervals.emplace_back(start, duration);
Expand All @@ -488,13 +498,18 @@ parse_instr_intervals_file(std::string path_to_file)
// 2) Overlapping intervals must be merged.
std::vector<instr_interval_t> instr_intervals_merged;
instr_intervals_merged.emplace_back(instr_intervals[0]);
for (instr_interval_t &interval : instr_intervals) {
for (size_t i = 1; i < instr_intervals.size(); ++i) {
instr_interval_t &interval = instr_intervals[i];
uint64 end = interval.start + interval.duration;
instr_interval_t &last_interval = instr_intervals_merged.back();
uint64 last_end = last_interval.start + last_interval.duration;
if (interval.start <= last_end) {
uint64 max_end = last_end > end ? last_end : end;
last_interval.duration = max_end - last_interval.start;
NOTIFY(0,
"Instruction interval starting at %" PRIu64 " has been merged with "
Copy link
Contributor

Choose a reason for hiding this comment

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

Maybe make this log more concise by denoting intervals as [start, end].

"instruction interval starting at %" PRIu64 " .\n",
last_interval.start, interval.start);
} else {
instr_intervals_merged.emplace_back(interval);
}
Expand Down Expand Up @@ -550,9 +565,9 @@ compute_irregular_trace_windows(std::vector<instr_interval_t> &instr_intervals)
// must have a duration long enough to cover the end of the program.
irregular_window_ptr =
(irregular_window_t *)dr_global_alloc(sizeof(irregular_window_t));
Copy link
Contributor

Choose a reason for hiding this comment

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

What about other uses of DELAY_FOREVER_THRESHOLD? I see instr_count_threshold() still returns that when current_no_trace_for_instrs == 0 (which IIUC will be true after the last window with this PR's change).

Copy link
Contributor Author

@edeiana edeiana Apr 12, 2025

Choose a reason for hiding this comment

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

My understanding is that instr_count_threshold() is used to differentiate between counting modes.
If it returns > DELAY_EXACT_THRESHOLD (like when current_no_trace_for_instrs == 0, which causes it to return DELAY_FOREVER_THRESHOLD), then the tracer adds to the global instruction count instr_count every DELAY_COUNTDOWN_UNIT.
Otherwise, when instr_count_threshold() returns a small "no_trace" window (like in the case of a "proper", user-defined window), then the tracer adds directly to the global instruction count.

However, what actually blocks the creation of the unwanted window is has_instr_count_threshold_to_enable_tracing(), which returns false when current_no_trace_for_instrs == 0.
Hence we return here: https://github.com/DynamoRIO/dynamorio/blob/master/clients/drcachesim/tracer/instr_counter.cpp#L190, before instr_count_threshold() or the creation of a new tracing window below.

Copy link
Contributor

Choose a reason for hiding this comment

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

if it returns > DELAY_EXACT_THRESHOLD (like when current_no_trace_for_instrs == 0, which causes it to return DELAY_FOREVER_THRESHOLD),

I didn't understand this statement. In your example does it return DELAY_EXACT_THRESHOLD or >DELAY_EXACT_THRESHOLD?

Even if other logic prevents its use, it seems weird to leave DELAY_FOREVER_THRESHOLD in there: it sounds like it still signifies "trace forever" for some cases, which I thought we don't want anymore.

Copy link
Contributor Author

@edeiana edeiana May 2, 2025

Choose a reason for hiding this comment

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

I didn't understand this statement. In your example does it return DELAY_EXACT_THRESHOLD or >DELAY_EXACT_THRESHOLD?

The previous behavior (which caused the bug), would have instr_count_threshold() return DELAY_FOREVER_THRESHOLD (which is > DELAY_EXACT_THRESHOLD) for the last "no trace" window.
So, we'd enter the if statement at https://github.com/DynamoRIO/dynamorio/blob/master/clients/drcachesim/tracer/instr_counter.cpp#L196 and not start a tracing window (like we expect) only until the program executed at least DELAY_FOREVER_THRESHOLD instructions, which is not that much, it's "only" 1024^3 (~1 billion instructions).
So, despite the name DELAY_FOREVER_THRESHOLD, we wouldn't delay tracing forever, we would delay only for ~1 billion instructions and then start tracing again.
I got confused by the name as well, but DELAY_FOREVER_THRESHOLD should have never been used as a value for a "no trace" window in the first place.
Looking at the comments of DELAY_EXACT_THRESHOLD and DELAY_FOREVER_THRESHOLD, these are used for counting modes: local vs global (https://github.com/DynamoRIO/dynamorio/blob/master/clients/drcachesim/tracer/instr_counter.cpp#L77).

Even if other logic prevents its use, it seems weird to leave DELAY_FOREVER_THRESHOLD in there: it sounds like it still signifies "trace forever" for some cases, which I thought we don't want anymore.

Is the suggestion to change the name of this constant because misleading?

Copy link
Contributor

Choose a reason for hiding this comment

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

I got confused by the name as well, but DELAY_FOREVER_THRESHOLD should have never been used as a value for a "no trace" window in the first place.
Looking at the comments of DELAY_EXACT_THRESHOLD and DELAY_FOREVER_THRESHOLD, these are used for counting modes: local vs global (https://github.com/DynamoRIO/dynamorio/blob/master/clients/drcachesim/tracer/instr_counter.cpp#L77).
Is the suggestion to change the name of this constant because misleading?

Indeed the name is confusing. Renaming would help.

// DELAY_FOREVER_THRESHOLD might be too small for long traces, but it doesn't matter
// because we trace_for_instrs = 0, so no window is created anyway.
irregular_window_ptr->no_trace_for_instrs = DELAY_FOREVER_THRESHOLD;
// We assume that a no_trace_for_instrs of UINT64_MAX is a long enough period that we
// stop tracing for the remaining execution of the traced program.
irregular_window_ptr->no_trace_for_instrs = UINT64_MAX;
irregular_window_ptr->trace_for_instrs = 0;
drvector_set_entry(&irregular_windows_list, num_intervals, irregular_window_ptr);
}
Expand Down
Loading