add core migration measuring and anti-bias to drmemtrace scheduler #6938

derekbruening · 2024-08-27T18:34:48Z

Today the drmemtrace scheduler is not preferring to keep an input on the same core it last ran on. This issue covers measuring the migration statistics and probably adding some kind of bias to avoid migrations.

Adds schedule statistics to memtrace_stream.h. Implements these statistics in the streams returned by scheduler_t. This initial round includes total switches, time preempts, and direct switch attempts and successes. Adds checks that these match the schedule_stats tool's values. Adds tests of the values to several key scheduler unit tests. Issue: #6938

Adds schedule statistics to memtrace_stream.h. Implements these statistics in the streams returned by scheduler_t. This initial round includes the following values: ``` [scheduler] Stats for output #0 [scheduler] Switch input->input : 16 [scheduler] Switch input->idle : 4 [scheduler] Switch idle->input : 3 [scheduler] Switch nop : 119 [scheduler] Quantum preempts : 131 [scheduler] Direct switch attempts : 0 [scheduler] Direct switch successes : 0 ``` The switches are split into those 4 categories to make it easier to compare to other sources of switch counts, such as `perf` where `perf` limited to a cgroup or process will be missing the `idle->input` switches, or schedule_stats which is missing the `input->idle` today. Adds checks that these match the schedule_stats tool's values. Adds tests of the values to several key scheduler unit tests. Issue: #6938

Adds the migration count to the new scheduler stats. Adds checks of the count to various unit tests. Issue: #6938

Adds the new scheduler-provided statistics to the schedule_stats tool. Adds a sanity test check. Issue: #6938

Adds the new scheduler-provided statistics to the schedule_stats tool. Adds a sanity test check. Tested on some larger apps where a high count of "nop" switches was sometimes found; as part of understanding those, I found a code path where if the runqueue is empty and the current thread is supposed to go unscheduled it would be run again instead. Fixed that here; unclear it has ever happened. Issue: #6938

Adds a std::mutex wrapper which stores the owner so we can assert on lock ownership. Adds lock ownership asserts to scheduler functions whose comments say they require a lock on entry. Fixes several cases of missing locks found by these asserts. Issue: #6938

Adds lock contention counters for mutex_dbg_owned::lock() in non-NDEBUG builds. While it's not there for release builds, the results in non-release should still be indicative of general lock behavior. Prints the stats for sched_lock_ with the other scheduler stats. Sample results on schedule_stats on a threadsig trace show a lot of contention even with only 3 cores: ``` $ clients/bin64/drmemtrace_launcher -indir ../build_x64_dbg_tests/drmemtrace.threadsig.5* -core_sharded -cores 3 -tool schedule_stats -verbose 1 [scheduler] Schedule lock acquired : 2196602 [scheduler] Schedule lock contended : 257580 ``` Issue: #6938

Adds lock contention counters for mutex_dbg_owned::lock() in non-NDEBUG builds. While it's not there for release builds, the results in non-release should still be indicative of general lock behavior. When I just changed the mutex_dbg_owned header, the relese build static drmemtrace tests (e.g., the burst_* ones) were all failing with floating point exceptions. It turns out it's due to different compilation units having different values for NDEBUG. I tried to make them all the same: but we have some files that contain `#undef NDEBUG` and other complexities. So I split the mutex_dbg_owned implementation into a .cpp file and have the mutex wrapper extra fields always present. Prints the stats for sched_lock_ with the other scheduler stats. Sample results on schedule_stats on a threadsig trace show a lot of contention even with only 3 cores, which the forthcoming separate runqueue change will address: ``` $ clients/bin64/drmemtrace_launcher -indir ../build_x64_dbg_tests/drmemtrace.threadsig.5* -core_sharded -cores 3 -tool schedule_stats -verbose 1 [scheduler] Schedule lock acquired : 2196602 [scheduler] Schedule lock contended : 257580 ``` Issue: #6938

Direct thread switches were not being counted as migrations in the original migration stats in PR #6950: we address that here. A test with multiple outputs will be added later as part of the move to separate runqueues, which is where this bug was discovered. Issue: #6938

Fixes a bug (discovered while testing separate runqueues) where direct switch requests with timeouts do not set blocked_start_time, resulting in re-using a prior (possibly 0) time and consequently much shorter timeouts. Reduces the default block_time_max parameter, as the bug was artificially reducing many instances and with the accurate timeout the existing defaults were no longer well-tuned. Updates unit tests. Issue: #6938

derekbruening · 2024-09-09T19:08:44Z

The plan is to implement separate runqueues per output. While testing the separate runqueue implementation I have found and fixed several bugs that affect the old global runqueue scheme as well. I'm going to include them as sub-parts of this issue:

Direct switch migrations were not being added to the migration stat counter
Direct switches were not setting blocked_start_time, resulting in too-short timeouts
Quantum time left was underflowing in certain conditions where preempt and voluntary switch triggers coincided

Testing the separate runqueues has led to a number of other changes I'd like to make:

Add a single simulator time scale option and have all the other options not be unitless (forcing the simulator to set every single one) but instead in simulated microsconds; apply to the existing quantum duration and block time max and possibly scale
Exiting early: xref Add scheduler exit-early feature to avoid long tail with sparse activity #6959 but not just when all are unscheduled
Retry using a counter instead of wall-clock time for instr quanta to reduce nondeterminism and make analyzers behavior more like simulators, simplifying testing

Fix bug underflowing quantum time when trying to correct overshoot but the quantum just expired and so is 0; or, we're replaying. Adds an assert. A test will come in the forthcoming rebalance test for per-output runqueues, which is where this bug was discovered. Issue: #6938

Replaces a comment with an official compiler annotation for a switch case fallthrough, to fix a warning under some compilers as part of running scheduler_unit_tests internally. Issue: #6938

Direct thread switches were not being counted as migrations in the original migration stats in PR #6950: we address that here. A test with multiple outputs will be added later as part of the move to separate runqueues, which is where this bug was discovered. Issue: #6938

Adds a -verbose 1 dump of the scheduler options at startup. This helps to record what options were passed in a particular run. Issue: #6938

Improves diagnostics by augmenting the all-runqueue printing: + It now constructs its many-line string in memory and then prints it all at once, to make it more atomic. + It includes the remaining blocked times for blocked inputs. + It is moved from pop_from_ready_queue() where the popped input is in flux to pick_next_input() where the current running input is valid. + It is printed more frequently. Also prints the size of the unscheduled queue when moving it. Issue: #6938

Adds a -verbose 1 dump of the scheduler options at startup. This helps to record what options were passed in a particular run. Issue: #6938

Improves diagnostics by augmenting the all-runqueue printing: + It now constructs its many-line string in memory and then prints it all at once, to make it more atomic. + It includes the remaining blocked times for blocked inputs. + It is moved from pop_from_ready_queue() where the popped input is in flux to pick_next_input() where the current running input is valid. + It is printed more frequently. Also prints the size of the unscheduled queue when moving it. Issue: #6938

Previously, a never-executed input could be moved to another output at any time, yet was still counted as a "migration". We change that here to consider a never-executed input to have executed at the initial simulation time seen on an output, so it will not be migrated until that threshold is met. An exception is the very first rebalance at init time for the initial allocation of inputs to outputs when inputs can be freely moved; this does not count as a migration. Adds a unit test. Issue: #6938

Fixes a race in the drmemtrace scheduler by making output_info_t.initial_cur_time atomic. Tested on ThreadSanitizer on the internal test where this was first reported. Issue: #6938

derekbruening · 2024-10-16T23:33:29Z

The scheduler was refactored to use per-core runqueues. Closing this.

Add a missing check that we're doing a dynamic schedule before trying to steal work when idle. There don't seem to be any consequences from the missing check but it is best to have it for clarity. Issue: #6938

Adds two statistics reported by the scheduler to the schedule_stats report: work steals and rebalances. Tests that something is printed out, but checks of the actual values are left to existing scheduler tests. Issue: #6938

While the schedule_stats tool already reports the migration count from the scheduler, that is only non-zero for a dynamic schedule, resulting in 0 for core-sharded-on-disk traces. We add "observed migrations" where schedule_stats looks for migrations on its own. This requires a global lock on each context switch, but experimental results show that this does not seem to cause noticeable overhead. Adds some testing. Issue: #6938

Adds two statistics reported by the scheduler to the schedule_stats report: work steals and rebalances. Tests that something is printed out, but checks of the actual values are left to existing scheduler tests. Issue: #6938

While the schedule_stats tool already reports the migration count from the scheduler, that is only non-zero for a dynamic schedule, resulting in 0 for core-sharded-on-disk traces. We add "observed migrations" where schedule_stats looks for migrations on its own. This requires a global lock on each context switch, but experimental results show that this does not seem to cause noticeable overhead. Adds some testing. Issue: #6938

Fixes an assert on the new observed_migrations stat added to schedule_stats in PR #7057. These observed_migrations are counted on the destination core, while the scheduler reports migrations away from a source core: so they can differ, causing the assert to fire. Fixed by moving it to only check the aggregated stats across all cores. Tested on the internal trace where the assert fired before. Issue: #6938

schedule_stats_t::get_total_counts() was not including scheduler-provided stats, as it was doing its own simple aggregation instead of calling aggregate_results(). We fix that here. That then triggers the newly added assert from PR #7057 which checks for the scheduler-provided value being exactly equal meaning there is no data available. It fires on the schedule_stats_test, which uses a mock stream which returns -1 for such a stat, so we end up with a negative value. We update the assert for that condition. Issue: #6938

…7060) schedule_stats_t::get_total_counts() was not including scheduler-provided stats, as it was doing its own simple aggregation instead of calling aggregate_results(). We fix that here. That then triggers the newly added assert from PR #7057 which checks for the scheduler-provided value being exactly equal meaning there is no data available. It fires on the schedule_stats_test, which uses a mock stream which returns -1 for such a stat, so we end up with a negative value. We update the assert for that condition. Issue: #6938

derekbruening self-assigned this Aug 27, 2024

derekbruening mentioned this issue Aug 27, 2024

i#6938 sched migrate: Add scheduler statistics #6939

Merged

derekbruening added the Component-DrMemtrace label Aug 27, 2024

derekbruening added a commit that referenced this issue Aug 29, 2024

i#6938 sched migrate: Add migration count to scheduler

480b49a

Adds the migration count to the new scheduler stats. Adds checks of the count to various unit tests. Issue: #6938

derekbruening mentioned this issue Aug 29, 2024

i#6938 sched migrate: Add migration count to scheduler #6950

Merged

derekbruening added a commit that referenced this issue Aug 29, 2024

i#6938 sched migrate: Add migration count to scheduler (#6950)

dbd993e

Adds the migration count to the new scheduler stats. Adds checks of the count to various unit tests. Issue: #6938

derekbruening added a commit that referenced this issue Aug 30, 2024

i#6938 sched migrate: Include scheduler stats in schedule_stats

4d32f86

Adds the new scheduler-provided statistics to the schedule_stats tool. Adds a sanity test check. Issue: #6938

derekbruening mentioned this issue Aug 30, 2024

i#6938 sched migrate: Include scheduler stats in schedule_stats #6955

Merged

derekbruening mentioned this issue Sep 4, 2024

i#6938 sched migrate: Add scheduler lock ownership asserts #6965

Merged

derekbruening mentioned this issue Sep 6, 2024

i#6938 sched migrate: Add lock contention stats #6968

Merged

derekbruening mentioned this issue Sep 9, 2024

i#6938 sched migrate: Count direct switches as migrations #6969

Merged

derekbruening mentioned this issue Sep 9, 2024

i#6938 sched migrate: Fix direct switch blocked_start_time #6970

Merged

derekbruening mentioned this issue Sep 9, 2024

i#6977: Fix quantum underflow #6973

Merged

derekbruening mentioned this issue Sep 9, 2024

i#6938 sched migrate: Use annotation for fallthrough #6975

Merged

This was referenced Sep 10, 2024

scheduler time in quantum underflows, leading to negative values #6977

Closed

scheduler not udpating direct switch block start time, resulting in too-short blocks #6978

Open

derekbruening mentioned this issue Oct 3, 2024

i#6938 sched migrate: Print blocked times in queues #7019

Merged

derekbruening added a commit that referenced this issue Oct 3, 2024

i#6938 sched migrate: Print configuration at startup

1aec206

Adds a -verbose 1 dump of the scheduler options at startup. This helps to record what options were passed in a particular run. Issue: #6938

derekbruening mentioned this issue Oct 3, 2024

i#6938 sched migrate: Print configuration at startup #7020

Merged

derekbruening added a commit that referenced this issue Oct 3, 2024

i#6938 sched migrate: Print configuration at startup (#7020)

5c9652f

Adds a -verbose 1 dump of the scheduler options at startup. This helps to record what options were passed in a particular run. Issue: #6938

derekbruening added a commit that referenced this issue Oct 4, 2024

i#6938 sched migrate: Print configuration at startup (#7020)

4c3fcb8

Adds a -verbose 1 dump of the scheduler options at startup. This helps to record what options were passed in a particular run. Issue: #6938

derekbruening mentioned this issue Oct 11, 2024

i#6938 sched migrate: Enforce migration threshold at the start #7038

Merged

derekbruening mentioned this issue Oct 15, 2024

i#6938 sched migrate: Make initial_cur_time atomic #7043

Merged

derekbruening closed this as completed Oct 16, 2024

derekbruening mentioned this issue Oct 22, 2024

i#6938 sched migrate: Add missing check for work stealing #7052

Merged

derekbruening mentioned this issue Oct 25, 2024

i#6938 sched migrate: Add steals + rebalances to schedule stats #7056

Merged

derekbruening mentioned this issue Oct 25, 2024

i#6938 sched migrate: Add observed migrations to schedule stats #7057

Merged

derekbruening mentioned this issue Oct 28, 2024

i#6938 migrate: Fix observed_migrations assert in schedule_stats #7059

Merged

derekbruening mentioned this issue Oct 29, 2024

i#6938 migrate: Include sched stats in query and fix related assert #7060

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

add core migration measuring and anti-bias to drmemtrace scheduler #6938

add core migration measuring and anti-bias to drmemtrace scheduler #6938

derekbruening commented Aug 27, 2024

derekbruening commented Sep 9, 2024

derekbruening commented Oct 16, 2024

add core migration measuring and anti-bias to drmemtrace scheduler #6938

add core migration measuring and anti-bias to drmemtrace scheduler #6938

Comments

derekbruening commented Aug 27, 2024

derekbruening commented Sep 9, 2024

derekbruening commented Oct 16, 2024