diff --git a/clients/drcachesim/common/memtrace_stream.h b/clients/drcachesim/common/memtrace_stream.h index 23e4d3af274..c0e27cb5b7a 100644 --- a/clients/drcachesim/common/memtrace_stream.h +++ b/clients/drcachesim/common/memtrace_stream.h @@ -64,6 +64,26 @@ namespace drmemtrace { /**< DrMemtrace tracing + simulation infrastructure names */ class memtrace_stream_t { public: + /** + * Statistics on the resulting schedule from interleaving and switching + * between the inputs. + */ + enum schedule_statistic_t { + /** Count of switches between inputs. */ + SCHED_STAT_SWITCHES, + /** + * Count of preempts due to time quantum expiration. Includes instances + * of the quantum expiring but no switch happening. + */ + SCHED_STAT_TIME_PREEMPTS, + /** Count of #TRACE_MARKER_TYPE_DIRECT_THREAD_SWITCH markers. */ + SCHED_STAT_DIRECT_SWITCH_ATTEMPTS, + /** Count of #TRACE_MARKER_TYPE_DIRECT_THREAD_SWITCH attempts that succeeded. */ + SCHED_STAT_DIRECT_SWITCH_SUCCESSES, + /** Count of statistic types. */ + SCHED_STAT_TYPE_COUNT, + }; + /** Destructor. */ virtual ~memtrace_stream_t() { @@ -240,6 +260,17 @@ class memtrace_stream_t { { return false; } + + /** + * Returns the value of the specified statistic for this output stream. + * The values for all output stream must be summed to obtain global counts. + * Returns -1 if statistics are not supported for this stream. + */ + virtual int64_t + get_schedule_statistic(schedule_statistic_t stat) const + { + return -1; + } }; /** diff --git a/clients/drcachesim/scheduler/scheduler.cpp b/clients/drcachesim/scheduler/scheduler.cpp index 69963ae6e47..e12c39bf524 100644 --- a/clients/drcachesim/scheduler/scheduler.cpp +++ b/clients/drcachesim/scheduler/scheduler.cpp @@ -664,6 +664,22 @@ scheduler_tmpl_t::stream_t::set_active(bool active) * Scheduler. */ +template +scheduler_tmpl_t::~scheduler_tmpl_t() +{ + for (unsigned int i = 0; i < outputs_.size(); ++i) { + VPRINT(this, 1, "Stats for output #%d\n", i); + VPRINT(this, 1, "%-25s: %9" PRId64 "\n", "Switches", + outputs_[i].stats[memtrace_stream_t::SCHED_STAT_SWITCHES]); + VPRINT(this, 1, "%-25s: %9" PRId64 "\n", "Time preempts", + outputs_[i].stats[memtrace_stream_t::SCHED_STAT_TIME_PREEMPTS]); + VPRINT(this, 1, "%-25s: %9" PRId64 "\n", "Direct switch attempts", + outputs_[i].stats[memtrace_stream_t::SCHED_STAT_DIRECT_SWITCH_ATTEMPTS]); + VPRINT(this, 1, "%-25s: %9" PRId64 "\n", "Direct switch successes", + outputs_[i].stats[memtrace_stream_t::SCHED_STAT_DIRECT_SWITCH_SUCCESSES]); + } +} + template bool scheduler_tmpl_t::check_valid_input_limits( @@ -2595,6 +2611,7 @@ scheduler_tmpl_t::set_cur_input(output_ordinal_t output, if (outputs_[output].prev_input >= 0) { std::lock_guard lock(*inputs_[outputs_[output].prev_input].lock); prev_workload = inputs_[outputs_[output].prev_input].workload; + ++outputs_[output].stats[memtrace_stream_t::SCHED_STAT_SWITCHES]; } std::lock_guard lock(*inputs_[input].lock); @@ -2895,6 +2912,8 @@ scheduler_tmpl_t::pick_next_input(output_ordinal_t outpu target->blocked_time = 0; target->unscheduled = false; } + ++outputs_[output].stats + [memtrace_stream_t::SCHED_STAT_DIRECT_SWITCH_SUCCESSES]; } else if (unscheduled_priority_.find(target)) { target->unscheduled = false; unscheduled_priority_.erase(target); @@ -2905,6 +2924,8 @@ scheduler_tmpl_t::pick_next_input(output_ordinal_t outpu "@%" PRIu64 "\n", output, prev_index, target->index, inputs_[prev_index].reader->get_last_timestamp()); + ++outputs_[output].stats + [memtrace_stream_t::SCHED_STAT_DIRECT_SWITCH_SUCCESSES]; } else { // We assume that inter-input dependencies are captured in // the _DIRECT_THREAD_SWITCH, _UNSCHEDULE, and _SCHEDULE markers @@ -3056,6 +3077,7 @@ scheduler_tmpl_t::process_marker(input_info_t &input, case TRACE_MARKER_TYPE_DIRECT_THREAD_SWITCH: { if (!options_.honor_direct_switches) break; + ++outputs_[output].stats[memtrace_stream_t::SCHED_STAT_DIRECT_SWITCH_ATTEMPTS]; memref_tid_t target_tid = marker_value; auto it = tid2input_.find(workload_tid_t(input.workload, target_tid)); if (it == tid2input_.end()) { @@ -3404,6 +3426,7 @@ scheduler_tmpl_t::next_record(output_ordinal_t output, preempt = !need_new_input; need_new_input = true; input->instrs_in_quantum = 0; + ++outputs_[output].stats[memtrace_stream_t::SCHED_STAT_TIME_PREEMPTS]; } } else if (options_.quantum_unit == QUANTUM_TIME) { if (cur_time == 0 || cur_time < input->prev_time_in_quantum) { @@ -3427,6 +3450,7 @@ scheduler_tmpl_t::next_record(output_ordinal_t output, preempt = !need_new_input; need_new_input = true; input->time_spent_in_quantum = 0; + ++outputs_[output].stats[memtrace_stream_t::SCHED_STAT_TIME_PREEMPTS]; } } } @@ -3687,6 +3711,16 @@ scheduler_tmpl_t::is_record_kernel(output_ordinal_t outp return inputs_[index].reader->is_record_kernel(); } +template +int64_t +scheduler_tmpl_t::get_statistic( + output_ordinal_t output, memtrace_stream_t::schedule_statistic_t stat) const +{ + if (stat >= memtrace_stream_t::SCHED_STAT_TYPE_COUNT) + return -1; + return outputs_[output].stats[stat]; +} + template typename scheduler_tmpl_t::stream_status_t scheduler_tmpl_t::set_output_active(output_ordinal_t output, diff --git a/clients/drcachesim/scheduler/scheduler.h b/clients/drcachesim/scheduler/scheduler.h index 5f3b2516461..6c8a426409a 100644 --- a/clients/drcachesim/scheduler/scheduler.h +++ b/clients/drcachesim/scheduler/scheduler.h @@ -1125,6 +1125,16 @@ template class scheduler_tmpl_t { return scheduler_->is_record_kernel(ordinal_); } + /** + * Returns the value of the specified statistic for this output stream. + * The values for all output stream must be summed to obtain global counts. + */ + int64_t + get_schedule_statistic(schedule_statistic_t stat) const override + { + return scheduler_->get_statistic(ordinal_, stat); + } + protected: scheduler_tmpl_t *scheduler_ = nullptr; int ordinal_ = -1; @@ -1153,7 +1163,7 @@ template class scheduler_tmpl_t { : ready_priority_(static_cast(get_time_micros())) { } - virtual ~scheduler_tmpl_t() = default; + virtual ~scheduler_tmpl_t(); /** * Initializes the scheduler for the given inputs, count of output streams, and @@ -1440,6 +1450,9 @@ template class scheduler_tmpl_t { bool at_eof = false; // Used for replaying wait periods. uint64_t wait_start_time = 0; + // Exported statistics. + std::vector stats = + std::vector(memtrace_stream_t::SCHED_STAT_TYPE_COUNT); }; // Used for reading as-traced schedules. @@ -1791,6 +1804,11 @@ template class scheduler_tmpl_t { // to kernel execution. bool is_record_kernel(output_ordinal_t output); + + int64_t + get_statistic(output_ordinal_t output, + memtrace_stream_t::schedule_statistic_t stat) const; + /////////////////////////////////////////////////////////////////////////// // Support for ready queues for who to schedule next: diff --git a/clients/drcachesim/tests/scheduler_unit_tests.cpp b/clients/drcachesim/tests/scheduler_unit_tests.cpp index 303393e4efb..ae344504d39 100644 --- a/clients/drcachesim/tests/scheduler_unit_tests.cpp +++ b/clients/drcachesim/tests/scheduler_unit_tests.cpp @@ -130,6 +130,21 @@ memref_is_nop_instr(memref_t &record) return pc != nullptr && instr_is_nop(instr); } +static void +verify_scheduler_stats(scheduler_t::stream_t *stream, int64_t switches, int64_t preempts, + int64_t direct_attempts, int64_t direct_successes) +{ + assert(stream->get_schedule_statistic(memtrace_stream_t::SCHED_STAT_SWITCHES) == + switches); + assert(stream->get_schedule_statistic(memtrace_stream_t::SCHED_STAT_TIME_PREEMPTS) == + preempts); + assert(stream->get_schedule_statistic( + memtrace_stream_t::SCHED_STAT_DIRECT_SWITCH_ATTEMPTS) == direct_attempts); + assert(stream->get_schedule_statistic( + memtrace_stream_t::SCHED_STAT_DIRECT_SWITCH_SUCCESSES) == + direct_successes); +} + static void test_serial() { @@ -1076,6 +1091,13 @@ test_synthetic() for (int i = 0; i < NUM_OUTPUTS; i++) { std::cerr << "cpu #" << i << " schedule: " << sched_as_string[i] << "\n"; } + // Check scheduler stats. # switches is the # of letter transitions; # preempts + // is the count of 3-letters-in-a-row sequences (3 is the quantum) except the + // last for an input (EOF doesn't count as a preempt). + verify_scheduler_stats(scheduler.get_stream(0), /*switches=*/10, /*preempts=*/6, + /*direct_attempts=*/0, /*direct_successes=*/0); + verify_scheduler_stats(scheduler.get_stream(1), /*switches=*/11, /*preempts=*/8, + /*direct_attempts=*/0, /*direct_successes=*/0); #ifndef WIN32 // XXX: Windows microseconds on test VMs are very coarse and stay the same // for long periods. Instruction quanta use wall-clock idle times, so @@ -1256,6 +1278,11 @@ test_synthetic_time_quanta() check_next(cpu0, ++time, scheduler_t::STATUS_EOF); if (scheduler.write_recorded_schedule() != scheduler_t::STATUS_SUCCESS) assert(false); + // Check scheduler stats. + verify_scheduler_stats(scheduler.get_stream(0), /*switches=*/2, /*preempts=*/2, + /*direct_attempts=*/0, /*direct_successes=*/0); + verify_scheduler_stats(scheduler.get_stream(1), /*switches=*/3, /*preempts=*/1, + /*direct_attempts=*/0, /*direct_successes=*/0); } { replay_file_checker_t checker; @@ -1377,6 +1404,13 @@ test_synthetic_with_timestamps() ".CC.C.II.IC.CC.F.FF.I.II.FF.F..BB.B.HH.HE.EE.BB.B.HH.H..DD.DA.AA.G.GG.DD.D._"); assert(sched_as_string[1] == ".FF.F.JJ.JJ.JJ.JJ.J.CC.C.II.I..EE.EB.BB.H.HH.EE.E..AA.A.GG.GD.DD.AA.A.GG.G."); + // Check scheduler stats. # switches is the # of letter transitions; # preempts + // is the count of 3-letters-in-a-row sequences (3 is the quantum) except the + // last for an input (EOF doesn't count as a preempt). + verify_scheduler_stats(scheduler.get_stream(0), /*switches=*/14, /*preempts=*/11, + /*direct_attempts=*/0, /*direct_successes=*/0); + verify_scheduler_stats(scheduler.get_stream(1), /*switches=*/14, /*preempts=*/9, + /*direct_attempts=*/0, /*direct_successes=*/0); } static void @@ -1461,6 +1495,13 @@ test_synthetic_with_priorities() ".BB.B.HH.HE.EE.BB.B.HH.H..FF.F.JJ.JJ.JJ.JJ.J.CC.C.II.I..DD.DA.AA.G.GG.DD.D._"); assert(sched_as_string[1] == ".EE.EB.BB.H.HH.EE.E..CC.C.II.IC.CC.F.FF.I.II.FF.F..AA.A.GG.GD.DD.AA.A.GG.G."); + // Check scheduler stats. # switches is the # of letter transitions; # preempts + // is the count of 3-letters-in-a-row sequences (3 is the quantum) except the + // last for an input (EOF doesn't count as a preempt). + verify_scheduler_stats(scheduler.get_stream(0), /*switches=*/14, /*preempts=*/9, + /*direct_attempts=*/0, /*direct_successes=*/0); + verify_scheduler_stats(scheduler.get_stream(1), /*switches=*/14, /*preempts=*/11, + /*direct_attempts=*/0, /*direct_successes=*/0); } static void @@ -1781,6 +1822,13 @@ test_synthetic_with_syscalls_multiple() assert(sched_as_string[0] == "BHHHFFFJJJJJJBEEHHHFFFBCCCEEIIIDDDBAAAGGGDDDB________B_______"); assert(sched_as_string[1] == "EECCCIIICCCBEEJJJHHHIIIFFFEAAAGGGBDDDAAAGGG________B"); + // Check scheduler stats. # switches is the # of letter transitions; # preempts + // is the count of 3-letters-in-a-row sequences (3 is the quantum) except the + // last for an input (EOF doesn't count as a preempt). + verify_scheduler_stats(scheduler.get_stream(0), /*switches=*/20, /*preempts=*/11, + /*direct_attempts=*/0, /*direct_successes=*/0); + verify_scheduler_stats(scheduler.get_stream(1), /*switches=*/17, /*preempts=*/10, + /*direct_attempts=*/0, /*direct_successes=*/0); } static void @@ -4173,6 +4221,8 @@ test_direct_switch() std::cerr << "cpu #" << i << " schedule: " << sched_as_string[i] << "\n"; } assert(sched_as_string[0] == CORE0_SCHED_STRING); + verify_scheduler_stats(scheduler.get_stream(0), /*switches=*/4, /*preempts=*/0, + /*direct_attempts=*/3, /*direct_successes=*/2); } { // Test disabling direct switches. @@ -4210,6 +4260,8 @@ test_direct_switch() std::cerr << "cpu #" << i << " schedule: " << sched_as_string[i] << "\n"; } assert(sched_as_string[0] == CORE0_SCHED_STRING); + verify_scheduler_stats(scheduler.get_stream(0), /*switches=*/4, /*preempts=*/0, + /*direct_attempts=*/0, /*direct_successes=*/0); } } @@ -5353,7 +5405,6 @@ test_main(int argc, const char *argv[]) test_kernel_switch_sequences(); test_random_schedule(); test_record_scheduler(); - dr_standalone_exit(); return 0; } diff --git a/clients/drcachesim/tools/schedule_stats.cpp b/clients/drcachesim/tools/schedule_stats.cpp index 47637430bbe..ca7d335a434 100644 --- a/clients/drcachesim/tools/schedule_stats.cpp +++ b/clients/drcachesim/tools/schedule_stats.cpp @@ -411,6 +411,25 @@ schedule_stats_t::aggregate_results(counters_t &total) { for (const auto &shard : shard_map_) { total += shard.second->counters; + // Sanity check against the scheduler's own stats, unless the trace + // is pre-scheduled. + if (TESTANY(OFFLINE_FILE_TYPE_CORE_SHARDED, shard.second->filetype)) + continue; + assert(shard.second->counters.total_switches == + shard.second->stream->get_schedule_statistic( + memtrace_stream_t::SCHED_STAT_SWITCHES)); + // We can only find a lower bound on preempts as the preempt stat from + // the scheduler includes no-switch cases. + assert(shard.second->counters.total_switches - + shard.second->counters.voluntary_switches <= + shard.second->stream->get_schedule_statistic( + memtrace_stream_t::SCHED_STAT_TIME_PREEMPTS)); + assert(shard.second->counters.direct_switch_requests == + shard.second->stream->get_schedule_statistic( + memtrace_stream_t::SCHED_STAT_DIRECT_SWITCH_ATTEMPTS)); + assert(shard.second->counters.direct_switches == + shard.second->stream->get_schedule_statistic( + memtrace_stream_t::SCHED_STAT_DIRECT_SWITCH_SUCCESSES)); } }