diff --git a/api/docs/release.dox b/api/docs/release.dox index 420c8eb5c73..c98907efa6d 100644 --- a/api/docs/release.dox +++ b/api/docs/release.dox @@ -255,6 +255,9 @@ Further non-compatibility-affecting changes include: input_workload_t::times_of_interest to the drmemtrace scheduler. - Added v2p_reader_t to parse a virtual-to-physical mapping in textproto format and v2p_info_t to hold that mapping in memory. + - Added -trace_instr_intervals_file option to the drmemtrace trace analysis tools + framework. The file must be in CSV format containing a tracing + interval per line where start and duration are expressed in number of instructions. **************************************************
diff --git a/clients/drcachesim/common/options.cpp b/clients/drcachesim/common/options.cpp index abf5a2d4674..8d8093b8c45 100644 --- a/clients/drcachesim/common/options.cpp +++ b/clients/drcachesim/common/options.cpp @@ -358,6 +358,13 @@ droption_t op_retrace_every_instrs( "TRACE_MARKER_TYPE_WINDOW_ID markers. For -offline traces, each window is placed " "into its own separate set of output files, unless -no_split_windows is set."); +droption_t op_trace_instr_intervals_file( + DROPTION_SCOPE_CLIENT, "trace_instr_intervals_file", "", + "File containing instruction intervals to trace.", + "File containing instruction intervals to trace in csv format. " + "Intervals are specified as a pair per line. Example in: " + "clients/drcachesim/tests/instr_intervals_example.csv"); + droption_t op_split_windows( DROPTION_SCOPE_CLIENT, "split_windows", true, "Whether -retrace_every_instrs should write separate files", diff --git a/clients/drcachesim/common/options.h b/clients/drcachesim/common/options.h index 501707defc9..1b5a01d6b54 100644 --- a/clients/drcachesim/common/options.h +++ b/clients/drcachesim/common/options.h @@ -131,6 +131,7 @@ extern dynamorio::droption::droption_t op_trace_for_instrs; extern dynamorio::droption::droption_t op_retrace_every_instrs; +extern dynamorio::droption::droption_t op_trace_instr_intervals_file; extern dynamorio::droption::droption_t op_split_windows; extern dynamorio::droption::droption_t op_exit_after_tracing; diff --git a/clients/drcachesim/tests/instr_intervals_example.csv b/clients/drcachesim/tests/instr_intervals_example.csv new file mode 100644 index 00000000000..44700bd2a34 --- /dev/null +++ b/clients/drcachesim/tests/instr_intervals_example.csv @@ -0,0 +1,3 @@ +100,10000, +40000,20000, +100000,1000, diff --git a/clients/drcachesim/tests/irregular-windows-simple.templatex b/clients/drcachesim/tests/irregular-windows-simple.templatex new file mode 100644 index 00000000000..bfdd2836d6a --- /dev/null +++ b/clients/drcachesim/tests/irregular-windows-simple.templatex @@ -0,0 +1,17 @@ +Hit delay threshold: enabling tracing. +Hit tracing window #0 limit: disabling tracing. +Hit retrace threshold: enabling tracing for window #1. +Hit tracing window #1 limit: disabling tracing. +Hit retrace threshold: enabling tracing for window #2. +Hit tracing window #2 limit: disabling tracing. +.* +---- ---- +Basic counts tool results: +.* +Total windows: [0-9]* +Window #0: +.* +Window #1: +.* +Window #2: +.* diff --git a/clients/drcachesim/tracer/instr_counter.cpp b/clients/drcachesim/tracer/instr_counter.cpp index 737e897bb58..2b50bf3e83d 100644 --- a/clients/drcachesim/tracer/instr_counter.cpp +++ b/clients/drcachesim/tracer/instr_counter.cpp @@ -37,13 +37,22 @@ #include "instr_counter.h" -#include +#include #include - #include #include +// These libraries are safe to use during initialization only. +// See api/docs/deployment.dox sec_static_DR. +#include +#include +#include +#include +#include +#include + #include "dr_api.h" +#include "dr_defines.h" #include "drmgr.h" #include "drreg.h" #include "options.h" @@ -72,16 +81,88 @@ static uint64 instr_count; // but to avoid the complexity of different instrumentation we need a threshold. #define DELAY_FOREVER_THRESHOLD (1024 * 1024 * 1024) -static std::atomic reached_trace_after_instrs; +static std::atomic reached_trace_after_instrs(false); std::atomic retrace_start_timestamp; +static std::atomic irregular_window_idx(0); +static drvector_t irregular_windows_list; +static uint num_irregular_windows = 0; + +void +delete_instr_window_lists() +{ + if (num_irregular_windows == 0) + return; + if (!drvector_delete(&irregular_windows_list)) + FATAL("Fatal error: irregular_windows_list global vector was not deleted."); +} + +void +maybe_increment_irregular_window_index() +{ + if (irregular_window_idx.load(std::memory_order_acquire) < num_irregular_windows) + irregular_window_idx.fetch_add(1, std::memory_order_release); +} + +struct irregular_window_t { + uint64 no_trace_for_instrs = 0; + uint64 trace_for_instrs = 0; +}; + +uint64 +get_initial_no_trace_for_instrs_value() +{ + if (op_trace_after_instrs.get_value() > 0) + return (uint64)op_trace_after_instrs.get_value(); + if (num_irregular_windows > 0) { + void *irregular_window_ptr = drvector_get_entry(&irregular_windows_list, 0); + if (irregular_window_ptr == nullptr) + FATAL("Fatal error: irregular window not found at index 0."); + return ((irregular_window_t *)irregular_window_ptr)->no_trace_for_instrs; + } + return 0; +} + +uint64 +get_current_trace_for_instrs_value() +{ + if (op_trace_for_instrs.get_value() > 0) + return (uint64)op_trace_for_instrs.get_value(); + if (num_irregular_windows > 0) { + uint i = irregular_window_idx.load(std::memory_order_acquire); + void *irregular_window_ptr = drvector_get_entry(&irregular_windows_list, i); + if (irregular_window_ptr == nullptr) + FATAL("Fatal error: irregular window not found at index %d.", i); + return ((irregular_window_t *)irregular_window_ptr)->trace_for_instrs; + } + return 0; +} + +// This function returns the no_trace interval for all windows except the first one. +// The no_trace interval for the first window is returned by +// get_initial_no_trace_for_instrs_value(). +uint64 +get_current_no_trace_for_instrs_value() +{ + if (op_retrace_every_instrs.get_value() > 0) + return (uint64)op_retrace_every_instrs.get_value(); + if (num_irregular_windows > 0) { + uint i = irregular_window_idx.load(std::memory_order_acquire); + void *irregular_window_ptr = drvector_get_entry(&irregular_windows_list, i); + if (irregular_window_ptr == nullptr) + FATAL("Fatal error: irregular window not found at index %d.", i); + return ((irregular_window_t *)irregular_window_ptr)->no_trace_for_instrs; + } + return 0; +} + static bool has_instr_count_threshold_to_enable_tracing() { - if (op_trace_after_instrs.get_value() > 0 && + if (get_initial_no_trace_for_instrs_value() > 0 && !reached_trace_after_instrs.load(std::memory_order_acquire)) return true; - if (op_retrace_every_instrs.get_value() > 0) + if (get_current_no_trace_for_instrs_value() > 0) return true; return false; } @@ -89,11 +170,13 @@ has_instr_count_threshold_to_enable_tracing() static uint64 instr_count_threshold() { - if (op_trace_after_instrs.get_value() > 0 && + uint64 initial_no_trace_for_instrs = get_initial_no_trace_for_instrs_value(); + if (initial_no_trace_for_instrs > 0 && !reached_trace_after_instrs.load(std::memory_order_acquire)) - return op_trace_after_instrs.get_value(); - if (op_retrace_every_instrs.get_value() > 0) - return op_retrace_every_instrs.get_value(); + return initial_no_trace_for_instrs; + uint64 current_no_trace_for_instrs = get_current_no_trace_for_instrs_value(); + if (current_no_trace_for_instrs > 0) + return current_no_trace_for_instrs; return DELAY_FOREVER_THRESHOLD; } @@ -128,7 +211,7 @@ hit_instr_count_threshold(app_pc next_pc) dr_mutex_unlock(mutex); return; } - if (op_trace_after_instrs.get_value() > 0 && + if (get_initial_no_trace_for_instrs_value() > 0 && !reached_trace_after_instrs.load(std::memory_order_acquire)) { NOTIFY(0, "Hit delay threshold: enabling tracing.\n"); retrace_start_timestamp.store(instru_t::get_timestamp()); @@ -347,9 +430,159 @@ event_inscount_thread_init(void *drcontext) DELAY_COUNTDOWN_UNIT; } +// Represents an interval as a pair in terms of number of instructions. +struct instr_interval_t { + instr_interval_t(uint64 start, uint64 duration) + : start(start) + , duration(duration) + { + } + + uint64 start = 0; + uint64 duration = 0; +}; + +// Function to order instruction intervals by start time in ascending order. +static bool +cmp_start_instr(const instr_interval_t &l, const instr_interval_t &r) +{ + return l.start < r.start; +} + +static std::vector +parse_instr_intervals_file(std::string path_to_file) +{ + std::vector instr_intervals; + std::ifstream file(path_to_file); + if (!file.is_open()) + FATAL("Fatal error: failed to open file %s.\n", path_to_file.c_str()); + + std::string line; + while (std::getline(file, line)) { + // Ignore empty lines, if any. + if (line.empty()) + continue; + std::stringstream ss(line); + std::string elem; + if (!std::getline(ss, elem, ',')) + FATAL("Fatal error: start instruction not found.\n"); + uint64 start = std::stoull(elem); + if (!std::getline(ss, elem, ',')) + FATAL("Fatal error: instruction duration not found.\n"); + uint64 duration = std::stoull(elem); + // Ignore the remaining comma-separated elements, if any. + + instr_intervals.emplace_back(start, duration); + } + file.close(); + + if (instr_intervals.empty()) { + FATAL("Fatal error: -trace_instr_intervals_file %s contains no intervals.\n", + path_to_file.c_str()); + } + + // Enforcing constraints on intervals: + // 1) They need to be ordered by start time. + std::sort(instr_intervals.begin(), instr_intervals.end(), cmp_start_instr); + + // 2) Overlapping intervals must be merged. + std::vector instr_intervals_merged; + instr_intervals_merged.emplace_back(instr_intervals[0]); + for (instr_interval_t &interval : instr_intervals) { + 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; + } else { + instr_intervals_merged.emplace_back(interval); + } + } + + return instr_intervals_merged; +} + +static void +free_trace_window_entry(void *entry) +{ + dr_global_free(entry, sizeof(irregular_window_t)); +} + +// Transforms instruction intervals from pairs to trace and no_trace +// number of instructions. Has the side effect of populating the read-only, global vector +// irregular_windows_list, and the global num_irregular_windows. +static void +compute_irregular_trace_windows(std::vector &instr_intervals) +{ + if (instr_intervals.empty()) + return; + + uint num_intervals = (uint)instr_intervals.size(); + num_irregular_windows = num_intervals + 1; + + // We don't need to synch accesses because this global vector is initialized here and + // then it's only read. + drvector_init(&irregular_windows_list, num_irregular_windows, /* synch = */ false, + free_trace_window_entry); + + irregular_window_t *irregular_window_ptr = + (irregular_window_t *)dr_global_alloc(sizeof(irregular_window_t)); + irregular_window_ptr->no_trace_for_instrs = instr_intervals[0].start; + irregular_window_ptr->trace_for_instrs = instr_intervals[0].duration; + drvector_set_entry(&irregular_windows_list, 0, irregular_window_ptr); + + for (uint i = 1; i < num_intervals; ++i) { + uint64 no_trace_for_instrs = instr_intervals[i].start - + (instr_intervals[i - 1].start + instr_intervals[i - 1].duration); + uint64 trace_for_instrs = instr_intervals[i].duration; + + irregular_window_ptr = + (irregular_window_t *)dr_global_alloc(sizeof(irregular_window_t)); + irregular_window_ptr->no_trace_for_instrs = no_trace_for_instrs; + irregular_window_ptr->trace_for_instrs = trace_for_instrs; + drvector_set_entry(&irregular_windows_list, i, irregular_window_ptr); + } + + // Last window. We are done setting all the irregular windows of the csv file. We + // generate one last non-tracing window in case the target program is still running. + // If the user wants to finish with a tracing window, the last window in the csv file + // 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)); + // 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; + irregular_window_ptr->trace_for_instrs = 0; + drvector_set_entry(&irregular_windows_list, num_intervals, irregular_window_ptr); +} + +static void +init_irregular_trace_windows() +{ + std::string path_to_file = op_trace_instr_intervals_file.get_value(); + if (!path_to_file.empty()) { + // Other instruction interval options (i.e., -trace_after_instrs, + // -trace_for_instrs, -retrace_every_instrs) are not compatible with + // -trace_instr_intervals_file. Check that they are not set. + if (op_trace_after_instrs.get_value() > 0 || + op_trace_for_instrs.get_value() > 0 || + op_retrace_every_instrs.get_value() > 0) { + FATAL("Fatal error: -trace_instr_intervals_file cannot be used with " + "-trace_after_instrs, -trace_for_instrs, or -retrace_every_instrs.\n"); + } + // Parse intervals file. + std::vector instr_intervals = + parse_instr_intervals_file(op_trace_instr_intervals_file.get_value()); + // Populate the irregular_windows_list global vector and num_irregular_windows. + compute_irregular_trace_windows(instr_intervals); + } +} + void event_inscount_init() { + init_irregular_trace_windows(); DR_ASSERT(std::atomic_is_lock_free(&reached_trace_after_instrs)); } diff --git a/clients/drcachesim/tracer/instr_counter.h b/clients/drcachesim/tracer/instr_counter.h index fca13b376a9..8d9c1820cf3 100644 --- a/clients/drcachesim/tracer/instr_counter.h +++ b/clients/drcachesim/tracer/instr_counter.h @@ -43,6 +43,21 @@ namespace drmemtrace { extern std::atomic retrace_start_timestamp; +void +delete_instr_window_lists(); + +void +maybe_increment_irregular_window_index(); + +uint64 +get_initial_no_trace_for_instrs_value(); + +uint64 +get_current_trace_for_instrs_value(); + +uint64 +get_current_no_trace_for_instrs_value(); + dr_emit_flags_t event_inscount_bb_analysis(void *drcontext, void *tag, instrlist_t *bb, bool for_trace, bool translating, void **user_data); diff --git a/clients/drcachesim/tracer/output.cpp b/clients/drcachesim/tracer/output.cpp index 3d1d1f658ab..b51a5060942 100644 --- a/clients/drcachesim/tracer/output.cpp +++ b/clients/drcachesim/tracer/output.cpp @@ -1036,7 +1036,7 @@ process_and_output_buffer(void *drcontext, bool skip_size_cap) if (op_offline.get_value() && data->file == INVALID_FILE) { // We've delayed opening a new window file to avoid an empty final file. - DR_ASSERT(has_tracing_windows() || op_trace_after_instrs.get_value() > 0 || + DR_ASSERT(has_tracing_windows() || get_initial_no_trace_for_instrs_value() > 0 || attached_midway); open_new_thread_file(drcontext, get_local_window(data)); } @@ -1067,7 +1067,7 @@ process_and_output_buffer(void *drcontext, bool skip_size_cap) instru->clamp_unit_header_timestamp(data->buf_base + stamp_offs, min_timestamp); } - if (has_tracing_windows() || op_trace_after_instrs.get_value() > 0) { + if (has_tracing_windows() || get_initial_no_trace_for_instrs_value() > 0) { min_timestamp = retrace_start_timestamp.load(std::memory_order_acquire); instru->clamp_unit_header_timestamp(data->buf_base + stamp_offs, min_timestamp); } @@ -1210,15 +1210,15 @@ process_and_output_buffer(void *drcontext, bool skip_size_cap) tracing_mode.store(BBDUP_MODE_TRACE, std::memory_order_release); set_local_mode(data, BBDUP_MODE_TRACE); } - } else if (op_trace_for_instrs.get_value() > 0) { + } else if (get_current_trace_for_instrs_value() > 0) { bool hit_window_end = false; for (mem_ref = data->buf_base + header_size; mem_ref < buf_ptr; mem_ref += instru->sizeof_entry()) { if (!window_changed && !hit_window_end && - op_trace_for_instrs.get_value() > 0) { + get_current_trace_for_instrs_value() > 0) { hit_window_end = count_traced_instrs(drcontext, instru->get_instr_count(mem_ref), - op_trace_for_instrs.get_value()); + get_current_trace_for_instrs_value()); // We have to finish this buffer so we'll go a little beyond the // precise requested window length. // XXX: For small windows this may be significant: we could go @@ -1228,6 +1228,13 @@ process_and_output_buffer(void *drcontext, bool skip_size_cap) } } if (hit_window_end) { + // Go to the next interval, if -trace_instr_intervals_file is set and + // num_irregular_windows > 0. + // Note: we assume no tracing interval comes first, then tracing interval, + // then we increment irregular_window_idx when we hit the end of the + // tacing interval here. + maybe_increment_irregular_window_index(); + if (op_offline.get_value() && op_split_windows.get_value()) { size_t add = instru->append_thread_exit(buf_ptr, dr_get_thread_id(drcontext)); diff --git a/clients/drcachesim/tracer/tracer.cpp b/clients/drcachesim/tracer/tracer.cpp index 7ccafbb8f16..6d8f6cab7d1 100644 --- a/clients/drcachesim/tracer/tracer.cpp +++ b/clients/drcachesim/tracer/tracer.cpp @@ -186,8 +186,9 @@ bbdup_instr_counting_enabled() { // XXX: with no other options -trace_for_instrs switches to counting mode once tracing // is done, so return true. Now that we have a NOP mode this could be changed. - return op_trace_after_instrs.get_value() > 0 || op_trace_for_instrs.get_value() > 0 || - op_retrace_every_instrs.get_value() > 0; + return get_initial_no_trace_for_instrs_value() > 0 || + get_current_trace_for_instrs_value() > 0 || + get_current_no_trace_for_instrs_value() > 0; } static bool @@ -470,7 +471,7 @@ instrumentation_init() if (align_attach_detach_endpoints()) tracing_mode.store(BBDUP_MODE_NOP, std::memory_order_release); - else if (op_trace_after_instrs.get_value() != 0) + else if (get_initial_no_trace_for_instrs_value() != 0) tracing_mode.store(BBDUP_MODE_COUNT, std::memory_order_release); else if (op_L0_filter_until_instrs.get_value()) tracing_mode.store(BBDUP_MODE_L0_FILTER, std::memory_order_release); @@ -489,7 +490,7 @@ event_post_attach() uint64 timestamp = instru_t::get_timestamp(); attached_timestamp.store(timestamp, std::memory_order_release); NOTIFY(1, "Fully-attached timestamp is " UINT64_FORMAT_STRING "\n", timestamp); - if (op_trace_after_instrs.get_value() != 0) { + if (get_initial_no_trace_for_instrs_value() != 0) { NOTIFY(1, "Switching to counting mode after attach\n"); tracing_mode.store(BBDUP_MODE_COUNT, std::memory_order_release); } else if (op_L0_filter_until_instrs.get_value()) { @@ -1582,7 +1583,7 @@ event_pre_syscall(void *drcontext, int sysnum) if (file_ops_func.handoff_buf == NULL && (op_L0I_filter.get_value() || (has_tracing_windows() && - op_trace_for_instrs.get_value() < 10 * INSTRS_PER_BUFFER))) { + get_current_trace_for_instrs_value() < 10 * INSTRS_PER_BUFFER))) { process_and_output_buffer(drcontext, false); } @@ -2003,6 +2004,7 @@ event_exit(void) num_filter_refs_racy = 0; exit_record_syscall(); + delete_instr_window_lists(); exit_io(); dr_mutex_destroy(mutex); diff --git a/clients/drcachesim/tracer/tracer.h b/clients/drcachesim/tracer/tracer.h index 2b017b05bc3..97cf99d218e 100644 --- a/clients/drcachesim/tracer/tracer.h +++ b/clients/drcachesim/tracer/tracer.h @@ -42,6 +42,7 @@ #include "dr_api.h" #include "drmemtrace.h" #include "instru.h" +#include "instr_counter.h" #include "named_pipe.h" #include "options.h" #include "physaddr.h" @@ -266,7 +267,8 @@ has_tracing_windows() // We return true for a single-window -trace_for_instrs (without -retrace) setup // since we rely on having window numbers for the end-of-block buffer output check // used for a single-window transition away from tracing. - return op_trace_for_instrs.get_value() > 0 || op_retrace_every_instrs.get_value() > 0; + return get_current_trace_for_instrs_value() > 0 || + get_current_no_trace_for_instrs_value() > 0; } static inline bool diff --git a/suite/tests/CMakeLists.txt b/suite/tests/CMakeLists.txt index 349eaf786a9..cfd936952d6 100644 --- a/suite/tests/CMakeLists.txt +++ b/suite/tests/CMakeLists.txt @@ -3784,6 +3784,12 @@ if (BUILD_CLIENTS) torunonly_drcachesim(windows-simple ${ci_shared_app} "-trace_after_instrs 20K -trace_for_instrs 5K -retrace_every_instrs 35K -tool basic_counts" "") + # The corresponding clients/drcachesim/tests/irregular-windows-simple.templatex of + # this test does not have precise instruction count for the irregular windows because + # of variation between different runs and platforms. + torunonly_drcachesim(irregular-windows-simple ${ci_shared_app} + "-trace_instr_intervals_file ${config_files_dir}/instr_intervals_example.csv -tool basic_counts" "") + # Test that "Warmup hits" and "Warmup misses" are printed out torunonly_drcachesim(warmup-valid ${ci_shared_app} "-warmup_refs 1" "")