diff --git a/cli/dispatcher/internal/compilecheck/compiler.go b/cli/dispatcher/internal/compilecheck/compiler.go index 983dd4f9c..748ed6902 100644 --- a/cli/dispatcher/internal/compilecheck/compiler.go +++ b/cli/dispatcher/internal/compilecheck/compiler.go @@ -80,6 +80,19 @@ type UnitResult struct { // Surface says whether the unit's reference assembly kept the API of the last Unity build, for a // successful unit something in the plan references; zero for any other unit. Surface SurfaceVerdict + // AssumedReferences names the referenced assemblies that were still compiling when the compile + // this result came from started, and that it read from Unity's build on the assumption that they + // keep Unity's public surface. + AssumedReferences []string + // CompiledAgainAfter names the referenced assembly whose changed surface proved an earlier + // compile of this unit wrong, so this result comes from compiling it again; empty when one + // compile was enough. + CompiledAgainAfter string + // DiscardedDuration is how long the compile this run threw away took. + DiscardedDuration time.Duration + // WaitedForRecord marks a unit that waited for the references still compiling rather than + // starting before them, because its recorded result might be replayed once they finished. + WaitedForRecord bool } // CommandRunner runs one compiler invocation, so tests can stand in for the real process. diff --git a/cli/dispatcher/internal/compilecheck/plan.go b/cli/dispatcher/internal/compilecheck/plan.go index 6fcc94133..a20a86b37 100644 --- a/cli/dispatcher/internal/compilecheck/plan.go +++ b/cli/dispatcher/internal/compilecheck/plan.go @@ -23,13 +23,14 @@ type CompileUnit struct { // every unit of an --all run. SelectedAsDependent bool // PlanReferences names the assemblies this one references that this run compiles too. It is - // what the scheduler waits for: a reference left out of the plan was not rebuilt, so its - // reference assembly from the last Unity build is already on disk and nothing has to wait. + // what the scheduler waits for, or starts ahead of: a reference left out of the plan was not + // rebuilt, so its reference assembly from the last Unity build is already on disk. PlanReferences []string - // KeptSurfaceReferences names the assemblies among PlanReferences whose rebuilt reference - // assembly the run found to describe the same public surface as Unity's, so this unit reads - // Unity's instead. The scheduler fills it when it starts the unit, once every reference is done, - // and nothing writes to it afterwards. Empty everywhere else. + // KeptSurfaceReferences names the assemblies among PlanReferences this unit reads Unity's + // reference assembly for: the ones whose rebuilt reference assembly the run found to describe + // the same public surface as Unity's, or assumed would while they were still compiling. The + // scheduler fills it when it starts the unit, and nothing writes to it afterwards. Empty + // everywhere else. KeptSurfaceReferences map[string]bool } diff --git a/cli/dispatcher/internal/compilecheck/scheduler.go b/cli/dispatcher/internal/compilecheck/scheduler.go index 42e144a79..48181ebb7 100644 --- a/cli/dispatcher/internal/compilecheck/scheduler.go +++ b/cli/dispatcher/internal/compilecheck/scheduler.go @@ -23,8 +23,16 @@ type unitCompletion struct { // schedule is the readiness bookkeeping of one run: how many of a unit's references are still // missing, and which units are waiting on each one. +// A unit's final state - compiled and kept, compiled and changed, failed, skipped or blocked - is +// decided once, after every unit of the plan it references has a final state of its own. A unit may +// start before that, but what it found counts only from then on. type schedule struct { - pending []int + pending []int + // pendingOwn counts, per unit, the references in pending that were selected for their own + // sources rather than through a reference of their own. + pendingOwn []int + // ownSources marks, per unit, that it was selected for its own sources. + ownSources []bool dependents [][]int // references lists, per unit, the units of the plan it references. references [][]int @@ -37,6 +45,7 @@ type schedule struct { blocked []bool // keptSurface marks, per unit, that it finished with the public surface of the last Unity build. keptSurface []bool + unitProgress } // compileOutcome is everything one run of the scheduler produced: the results it has, and what it @@ -77,12 +86,14 @@ type schedulerRun struct { referenceSkips int } -// compileUnits compiles a plan's assemblies, starting each one as soon as the assemblies it -// references have been compiled and keeping at most jobs of them running at a time. It reports the -// results of the units it compiled, in the plan's order, and how many it left out. +// compileUnits compiles a plan's assemblies, keeping at most jobs of them running at a time. It +// reports the results of the units it compiled, in the plan's order, and how many it left out. +// A unit starts once every assembly it references has a final state, or - when it has to compile +// anyway - once every one of them selected for its own sources has, assuming the dependents still +// compiling keep Unity's public surface. A unit whose assumption turns out wrong compiles again. // Why the units cannot simply run in the plan's order all at once: a dependent reads the reference -// assembly its reference writes, so starting it early would compile it against the previous run's -// output or against nothing at all. +// assembly its reference writes when that one changed its surface, so starting it before anything is +// known would mostly compile it against the wrong file. func compileUnits( ctx context.Context, compiler Compiler, plan BuildPlan, jobs int, ) (compileOutcome, error) { @@ -108,16 +119,23 @@ func compileUnits( compiled: make([]bool, len(plan.Units)), completions: make(chan unitCompletion, len(plan.Units)), } + for index := range plan.Units { + run.offer(index) + } var failure error for { if failure == nil { - if err := run.startReadyUnits(jobs); err != nil { + if err := run.startAndSettle(jobs); err != nil { failure = err cancel() } } if run.running == 0 { + if failure == nil { + failure = run.unfinishedError() + } + break } if err := run.collectOneCompletion(); err != nil && failure == nil { @@ -141,22 +159,32 @@ func compileUnits( // the ones that have nothing left to learn from compiling. func (run *schedulerRun) startReadyUnits(jobs int) error { for run.running < jobs && len(run.state.ready) > 0 { - index := run.state.ready[0] - run.state.ready = run.state.ready[1:] + index := run.state.takeNext() // Why the block is read before the skip: a blocked unit has no result to compare against // anything, so asking whether its references kept their surface answers nothing. - if run.skipBlockedUnit(index) { - continue - } - skipped, err := run.skipUnchangedDependent(index) + blocked, err := run.skipBlockedUnit(index) if err != nil { return err } - if skipped { + if blocked { continue } + // Why the skip is asked only once every reference is final: until then a reference may + // still change its surface, and a unit queued early was queued because it compiles anyway. + if run.state.pending[index] == 0 { + skipped, err := run.skipUnchangedDependent(index) + if err != nil { + return err + } + if skipped { + continue + } + } + unit, assumed := run.startingUnit(index) + run.state.assumed[index] = assumed + run.state.started[index] = true run.running++ - go run.compileOneUnit(index, run.startingUnit(index), len(run.state.dependents[index]) > 0) + go run.compileOneUnit(index, unit, len(run.state.dependents[index]) > 0) } return nil @@ -174,19 +202,29 @@ func (run *schedulerRun) startReadyUnits(jobs int) error { // non-source key. // Removing them made the first successful run after an error compile every dependent again even // when the assembly with errors came back with the same reference assembly. -func (run *schedulerRun) skipBlockedUnit(index int) bool { +func (run *schedulerRun) skipBlockedUnit(index int) (bool, error) { if !run.state.blocked[index] { - return false + return false, nil + } + // Why a unit queued early is only taken out of the queue here: it is decided once every + // reference it has is, like any other unit, and the last of them to finish offers it again. + if run.state.pending[index] != 0 { + return true, nil + } + if err := run.markFinal(index); err != nil { + return false, err } run.state.blockDependents(index) - run.state.release(index, false) + run.releaseAndOffer(index, false) - return true + return true, nil } // skipUnchangedDependent leaves out a unit this run picked up only because something it references // was recompiled, when every one of those came out with the public surface the last Unity build -// recorded: compiling it would read exactly the API it was last compiled against. +// recorded: compiling it would read exactly the API it was last compiled against. It counts as +// having kept Unity's surface, so the units that started before it finished read Unity's reference +// assembly for it, as they assumed. // Why its earlier outputs are removed rather than left alone: a reference assembly an earlier run // wrote would otherwise be picked up as this run's own output, and the units below it would be // compiled against a result this run never produced. @@ -198,30 +236,45 @@ func (run *schedulerRun) skipUnchangedDependent(index int) (bool, error) { if err := run.compiler.removeUnitOutputs(run.plan, unit); err != nil { return false, err } + if err := run.markFinal(index); err != nil { + return false, err + } run.referenceSkips++ - run.state.release(index, false) + run.state.keptSurface[index] = true + run.releaseAndOffer(index, false) return true, nil } -// startingUnit is the unit at index as it is about to start, carrying which of the references it -// waited for kept the surface of the last Unity build. +// startingUnit is the unit at index as it would start now, carrying which of its references it +// reads from Unity's build: the final ones that kept the surface of the last Unity build, and the +// ones without a final state yet, which it assumes will. It also reports the latter. // Why a copy made here rather than a lookup from the unit's goroutine: the loop writes those answers -// as units finish, while the units it already started are still running, and every reference of this -// unit is done by now, so the copy is final. Why on the unit rather than passed alongside: the -// response file, the changed-files check and every key read it from the unit, so none of them can -// end up pointing at a different reference assembly than the compile does. -func (run *schedulerRun) startingUnit(index int) CompileUnit { +// as units finish, while the units it already started are still running. Why on the unit rather than +// passed alongside: the response file, the changed-files check and every key read it from the unit, +// so none of them can end up pointing at a different reference assembly than the compile does. +// Why an assumed reference is named rather than left to the missing-output fallback: an earlier run +// may have left its output on disk, and reading that would compile against a result this run never +// produced. +func (run *schedulerRun) startingUnit(index int) (CompileUnit, []int) { unit := run.plan.Units[index] kept := map[string]bool{} + assumed := []int{} for _, reference := range run.state.references[index] { + name := run.plan.Units[reference].Assembly.AssemblyName + if !run.state.final[reference] { + assumed = append(assumed, reference) + kept[name] = true + + continue + } if run.state.keptSurface[reference] { - kept[run.plan.Units[reference].Assembly.AssemblyName] = true + kept[name] = true } } unit.KeptSurfaceReferences = kept - return unit + return unit, assumed } // compileOneUnit produces one unit's result - by compiling it, or by replaying the previous run's @@ -242,10 +295,14 @@ func (run *schedulerRun) compileOneUnit(index int, unit CompileUnit, readByDepen run.completions <- unitCompletion{index: index, result: result, keptSurface: result.Surface.Kept, err: err} } -// collectOneCompletion waits for one unit to finish and hands what it produced to the schedule. +// collectOneCompletion waits for one unit to finish and holds what it produced until the unit's +// final state can be decided. // Why a failure stops the run: it means the compiler itself could not be started, which every // remaining unit would hit as well. Compile errors are not failures here - they arrive as // diagnostics and the run continues so that one pass reports all of them. +// Why nothing is released or blocked here: a unit that started before its references finished may +// still have its result thrown away, and the errors or the surface of a result nobody keeps must not +// decide anything for the units below it. func (run *schedulerRun) collectOneCompletion() error { completion := <-run.completions run.running-- @@ -253,15 +310,8 @@ func (run *schedulerRun) collectOneCompletion() error { return completion.err } run.results[completion.index] = completion.result - run.compiled[completion.index] = true - // Why a replayed result blocks the same way a compiled one does: it says the assembly has - // errors, and whether this run learned that from csc or from what the last run recorded changes - // nothing about the reference assembly the units below it would have to read. - if !completion.result.Succeeded { - run.state.blockDependents(completion.index) - } - run.state.keptSurface[completion.index] = completion.keptSurface - run.state.release(completion.index, !completion.keptSurface) + run.state.pendingKept[completion.index] = completion.keptSurface + run.state.finished[completion.index] = true return nil } @@ -291,7 +341,8 @@ func (run *schedulerRun) blockedNames() []string { return names } -// newSchedule counts what every unit is waiting for and queues the units waiting for nothing. +// newSchedule counts what every unit is waiting for. The caller offers every unit once, which queues +// the ones waiting for nothing. func newSchedule(plan BuildPlan) *schedule { indexByName := make(map[string]int, len(plan.Units)) for index, unit := range plan.Units { @@ -300,12 +351,18 @@ func newSchedule(plan BuildPlan) *schedule { state := &schedule{ pending: make([]int, len(plan.Units)), + pendingOwn: make([]int, len(plan.Units)), + ownSources: make([]bool, len(plan.Units)), dependents: make([][]int, len(plan.Units)), references: make([][]int, len(plan.Units)), ready: []int{}, changedInputs: make([]int, len(plan.Units)), blocked: make([]bool, len(plan.Units)), keptSurface: make([]bool, len(plan.Units)), + unitProgress: newUnitProgress(len(plan.Units)), + } + for index, unit := range plan.Units { + state.ownSources[index] = !unit.SelectedAsDependent } for index, unit := range plan.Units { for _, reference := range unit.PlanReferences { @@ -314,38 +371,47 @@ func newSchedule(plan BuildPlan) *schedule { continue } state.pending[index]++ + if state.ownSources[referenceIndex] { + state.pendingOwn[index]++ + } state.dependents[referenceIndex] = append(state.dependents[referenceIndex], index) state.references[index] = append(state.references[index], referenceIndex) } } - for index := range plan.Units { - if state.pending[index] == 0 { - state.ready = append(state.ready, index) - } - } return state } // blockDependents marks every unit waiting on this one as one this run must not compile. -// Why marking rather than removing from the queue: a unit is only queued once everything it waits -// for is done, so the ones marked here have not been queued yet and are read as they come up. +// Why marking rather than removing from the queue: a queued unit is read as it comes up, and one that +// already started is read when its final state is decided. func (state *schedule) blockDependents(index int) { for _, dependent := range state.dependents[index] { state.blocked[dependent] = true } } -// release hands the units that were waiting on a finished one to the ready queue, recording whether -// what it produced still describes the same public surface as the last Unity build. -func (state *schedule) release(index int, changed bool) { +// release tells the units waiting on one that just got its final state that it has, recording +// whether what it produced still describes the same public surface as the last Unity build, and +// reports those units so the caller can decide which of them to queue. +// Why a unit that assumed this one is marked stale only when it changed: it read Unity's reference +// assembly for it, which is exactly right when the surface was kept. A failed or blocked one blocks +// it through blockDependents instead. +func (state *schedule) release(index int, changed bool) []int { for _, dependent := range state.dependents[index] { state.pending[dependent]-- - if changed { - state.changedInputs[dependent]++ + if state.ownSources[index] { + state.pendingOwn[dependent]-- } - if state.pending[dependent] == 0 { - state.ready = append(state.ready, dependent) + if !changed { + continue + } + state.changedInputs[dependent]++ + if !state.stale[dependent] && containsIndex(state.assumed[dependent], index) { + state.stale[dependent] = true + state.staleCause[dependent] = index } } + + return state.dependents[index] } diff --git a/cli/dispatcher/internal/compilecheck/scheduler_optimistic_test.go b/cli/dispatcher/internal/compilecheck/scheduler_optimistic_test.go new file mode 100644 index 000000000..db0725c06 --- /dev/null +++ b/cli/dispatcher/internal/compilecheck/scheduler_optimistic_test.go @@ -0,0 +1,564 @@ +package compilecheck + +import ( + "context" + "fmt" + "sort" + "strings" + "testing" + "time" +) + +// weightHold is how long the fake compile of a reference takes in a test that checks a unit does not +// start while it runs. Why a hold rather than a gate there: nothing is meant to start, so there is +// nothing to wait for, and a slow machine can only let such a test pass, never fail it. +const weightHold = 60 * time.Millisecond + +// optimisticPlanRun is a plan of named units with Unity's reference assembly of each one on disk and +// a fake compiler that, unless told otherwise, writes a reference assembly that differs from it. +// Why Unity's files are written for every unit: the surface verdict compares the two files, and a +// unit without Unity's file never counts as having kept its surface. +type optimisticPlanRun struct { + plan BuildPlan + recorder *schedulerRecorder + compiler Compiler + // jobs caps how many units compile at once. + jobs int +} + +// newOptimisticPlanRun lays out the plan, marking the named dependents as units this run picks up +// only through a reference. +func newOptimisticPlanRun( + t *testing.T, references map[string][]string, dependents []string, names ...string, +) *optimisticPlanRun { + t.Helper() + plan := newSchedulerPlan(references, names...) + markSelectedAsDependent(t, plan, dependents...) + recorder := newSchedulerRecorder(0) + compiler := newSchedulerCompiler(t, recorder) + for _, name := range names { + writeUnityReferenceAssembly(t, compiler.ProjectRoot, name, keptSurfaceOf(name)) + recorder.surfaces[name] = "changed " + name + } + + return &optimisticPlanRun{plan: plan, recorder: recorder, compiler: compiler, jobs: 8} +} + +// keep makes the named units come out with Unity's public surface. +func (run *optimisticPlanRun) keep(names ...string) { + for _, name := range names { + run.recorder.surfaces[name] = keptSurfaceOf(name) + } +} + +// fail makes the named unit report a compile error and write no reference assembly. +func (run *optimisticPlanRun) fail(name string) { + run.recorder.output[name] = failingCompilerOutput(name) + delete(run.recorder.surfaces, name) +} + +// compile runs the plan and fails the test when the run could not finish. +func (run *optimisticPlanRun) compile(t *testing.T) compileOutcome { + t.Helper() + outcome, err := compileUnits(context.Background(), run.compiler, run.plan, run.jobs) + if err != nil { + t.Fatalf("expected the run to succeed, got error: %v", err) + } + + return outcome +} + +// newOptimisticCachedProject lays out a project the input key can read, marking the named dependents +// as units this run picks up only through a reference, and a fake compiler that writes a reference +// assembly differing from Unity's for every unit. +func newOptimisticCachedProject( + t *testing.T, references map[string][]string, dependents []string, names ...string, +) (*cachedSchedulerProject, *schedulerRecorder) { + t.Helper() + project := newCachedSchedulerProject(t, references, names...) + markSelectedAsDependent(t, project.plan, dependents...) + + return project, newCachedSchedulerRecorder(names...) +} + +// chainReferences is the plan most tests here use: X and K are selected for their own sources, D1 +// references both, and D2 references X and D1. The tests hold K until D2 begins, so D1 has not +// started when D2 does. +var chainReferences = map[string][]string{"D1": {"X", "K"}, "D2": {"X", "D1"}} + +// sortedNames copies names into ordinal order, for comparing sets of names. +func sortedNames(names []string) []string { + sorted := append([]string{}, names...) + sort.Strings(sorted) + + return sorted +} + +// warningOutput is what csc prints for an assembly that compiles with one warning. +func warningOutput(name string, message string) fakeCompilerOutput { + return fakeCompilerOutput{ + stdout: "Assets/" + name + "/" + name + ".cs(1,7): warning CS0168: " + message, + } +} + +// Verifies a dependent that must compile starts as soon as every assembly it references that was +// selected for its own sources finished, reading Unity's reference assembly for the dependent it +// references that has not even started - not the output an earlier run left for it - and keeps that +// compile when the dependent turns out to keep Unity's surface. +func TestCompileUnitsStartsADependentBeforeTheDependentsItReferencesFinish(t *testing.T) { + project, recorder := newOptimisticCachedProject(t, chainReferences, []string{"D1", "D2"}, "X", "K", "D1", "D2") + recorder.holdUntilBegun(t, "K", "D2") + recorder.surfaces["K"] = keptSurfaceOf("K") + recorder.surfaces["D1"] = keptSurfaceOf("D1") + writeStaleUnitOutput(t, project.root, project.plan, "D1") + + results := project.compileOrFail(t, recorder) + + assertStrings(t, "units finished when D2 started", sortedNames(recorder.finishedWhen["D2"]), []string{"X"}) + if recorder.runs["D2"] != 1 { + t.Errorf("D2 compiled %d times, want 1", recorder.runs["D2"]) + } + assertReferenceFlags(t, project.writtenResponseFile(t, "D2"+responseFileExtension), + []string{unityReferenceFlag("D1"), producedReferenceFlag(project.plan, "X")}, + []string{producedReferenceFlag(project.plan, "D1")}) + assertStrings(t, "results", compiledNames(results), []string{"X", "K", "D1", "D2"}) + assertStrings(t, "D2 assumed", resultOf(t, results, "D2").AssumedReferences, []string{"D1"}) + if again := resultOf(t, results, "D2").CompiledAgainAfter; again != "" { + t.Errorf("D2 compiled again after %q, want once", again) + } +} + +// Verifies an assembly selected for its own sources starts before a dependent it references +// finishes, too. +func TestCompileUnitsStartsAnEditedAssemblyBeforeTheDependentsItReferencesFinish(t *testing.T) { + run := newOptimisticPlanRun(t, map[string][]string{"D1": {"X", "K"}, "Y": {"X", "D1"}}, + []string{"D1"}, "X", "K", "D1", "Y") + run.recorder.holdUntilBegun(t, "K", "Y") + run.keep("K", "D1") + + outcome := run.compile(t) + + assertStrings(t, "units finished when Y started", sortedNames(run.recorder.finishedWhen["Y"]), []string{"X"}) + assertStrings(t, "results", compiledNames(outcome.Units), []string{"X", "K", "D1", "Y"}) + assertStrings(t, "Y assumed", resultOf(t, outcome.Units, "Y").AssumedReferences, []string{"D1"}) +} + +// Verifies a dependent still waits for a reference selected for its own sources: such a reference +// is likely to change its surface, so starting before it would mostly be wasted. +func TestCompileUnitsWaitsForAReferenceWhoseOwnSourcesChanged(t *testing.T) { + run := newOptimisticPlanRun(t, map[string][]string{"D": {"X", "Y"}}, []string{"D"}, "X", "Y", "D") + run.recorder.holdByUnit["Y"] = weightHold + run.keep("Y") + + run.compile(t) + + if !containsLine(run.recorder.finishedWhen["D"], "Y") { + t.Errorf("D started before Y finished; finished then: %v", run.recorder.finishedWhen["D"]) + } +} + +// Verifies a dependent none of whose finished references changed its surface does not start early: +// it may still be skipped once the rest finish, and here it is. +func TestCompileUnitsDoesNotStartADependentBeforeAReferenceIsKnownToHaveChanged(t *testing.T) { + run := newOptimisticPlanRun(t, map[string][]string{"D1": {"X"}, "D2": {"K", "D1"}}, + []string{"D1", "D2"}, "X", "K", "D1", "D2") + run.recorder.holdByUnit["D1"] = weightHold + run.keep("K", "D1") + + outcome := run.compile(t) + + if run.recorder.started["D2"] { + t.Error("D2 should not have started before any reference was known to have changed") + } + assertStrings(t, "results", compiledNames(outcome.Units), []string{"X", "K", "D1"}) + if outcome.Skipped != 1 { + t.Errorf("skipped = %d, want 1", outcome.Skipped) + } +} + +// Verifies a dependent blocked by a reference with errors does not start early, although another +// reference it waits for is a dependent still compiling. +func TestCompileUnitsDoesNotStartABlockedDependentOptimistically(t *testing.T) { + run := newOptimisticPlanRun(t, map[string][]string{"D1": {"X"}, "D2": {"A", "D1"}}, + []string{"D1", "D2"}, "X", "A", "D1", "D2") + run.recorder.holdByUnit["D1"] = weightHold + run.fail("A") + run.keep("D1") + + outcome := run.compile(t) + + if run.recorder.started["D2"] { + t.Error("a blocked dependent should not have started") + } + assertStrings(t, "blocked", outcome.Blocked, []string{"D2"}) + assertStrings(t, "results", compiledNames(outcome.Units), []string{"X", "A", "D1"}) +} + +// Verifies a dependent that started before a dependent it references finished is compiled again, +// against this run's output, when that reference changed its surface, and that only the second +// compile's diagnostics are reported. +func TestCompileUnitsCompilesADependentAgainWhenAnAssumedReferenceChangedItsSurface(t *testing.T) { + project, recorder := newOptimisticCachedProject(t, chainReferences, []string{"D1", "D2"}, "X", "K", "D1", "D2") + recorder.holdUntilBegun(t, "K", "D2") + recorder.holdByUnit["D2"] = 5 * time.Millisecond + recorder.surfaces["K"] = keptSurfaceOf("K") + recorder.outputByRun["D2"] = []fakeCompilerOutput{ + warningOutput("D2", "first compile"), warningOutput("D2", "second compile"), + } + + results := project.compileOrFail(t, recorder) + + if recorder.runs["D2"] != 2 { + t.Fatalf("D2 compiled %d times, want 2", recorder.runs["D2"]) + } + if !containsLine(recorder.finishedWhen["D2"], "D1") { + t.Errorf("the second compile of D2 started before D1 finished; finished then: %v", recorder.finishedWhen["D2"]) + } + assertReferenceFlags(t, project.writtenResponseFile(t, "D2"+responseFileExtension), + []string{producedReferenceFlag(project.plan, "D1")}, []string{unityReferenceFlag("D1")}) + d2 := resultOf(t, results, "D2") + if len(d2.Diagnostics) != 1 || d2.Diagnostics[0].Message != "second compile" { + t.Errorf("D2 diagnostics = %+v, want only the second compile's warning", d2.Diagnostics) + } + if d2.CompiledAgainAfter != "D1" || d2.DiscardedDuration <= 0 || len(d2.AssumedReferences) != 0 { + t.Errorf("D2 = %+v, want compiled again after D1, with a discarded duration and nothing assumed", d2) + } +} + +// Verifies a dependent whose two assumed references both changed their surface, at different +// times, is compiled twice and no more. +func TestCompileUnitsCompilesAStaleDependentOnlyOnceMore(t *testing.T) { + run := newOptimisticPlanRun(t, map[string][]string{ + "D1": {"X", "K1"}, "D1b": {"X", "K2"}, "D2": {"X", "D1", "D1b"}, + }, []string{"D1", "D1b", "D2"}, "X", "K1", "K2", "D1", "D1b", "D2") + run.recorder.holdUntilBegun(t, "K1", "D2") + run.recorder.holdUntilBegun(t, "K2", "D2") + run.recorder.holdByUnit["K2"] = 40 * time.Millisecond + run.keep("K1", "K2") + + run.compile(t) + + if run.recorder.runs["D2"] != 2 { + t.Fatalf("D2 compiled %d times, want 2", run.recorder.runs["D2"]) + } + for _, reference := range []string{"D1", "D1b"} { + if !containsLine(run.recorder.finishedWhen["D2"], reference) { + t.Errorf("the last compile of D2 started before %s finished; finished then: %v", + reference, run.recorder.finishedWhen["D2"]) + } + } +} + +// Verifies the surface verdict of a compile that was thrown away decides nothing: the dependent +// below it compiles again against the output of the compile that was kept. +func TestCompileUnitsIgnoresTheVerdictOfADiscardedCompile(t *testing.T) { + references := map[string][]string{"D1": {"X", "K"}, "D2": {"X", "D1"}, "D3": {"X", "D2"}} + project, recorder := newOptimisticCachedProject(t, references, []string{"D1", "D2", "D3"}, + "X", "K", "D1", "D2", "D3") + recorder.holdUntilBegun(t, "K", "D2", "D3") + recorder.surfaces["K"] = keptSurfaceOf("K") + recorder.surfacesByRun["D2"] = []string{keptSurfaceOf("D2"), "changed D2"} + + project.compileOrFail(t, recorder) + + if recorder.runs["D3"] != 2 { + t.Fatalf("D3 compiled %d times, want 2", recorder.runs["D3"]) + } + assertReferenceFlags(t, project.writtenResponseFile(t, "D3"+responseFileExtension), + []string{producedReferenceFlag(project.plan, "D2")}, []string{unityReferenceFlag("D2")}) +} + +// Verifies the errors of a compile that was thrown away block nothing: the dependent below it is +// compiled, and the unit is reported with the outcome of the compile that was kept. +func TestCompileUnitsIgnoresTheErrorsOfADiscardedCompile(t *testing.T) { + run := newOptimisticPlanRun(t, map[string][]string{"D1": {"X", "K"}, "D2": {"X", "D1"}, "D3": {"X", "D2"}}, + []string{"D1", "D2", "D3"}, "X", "K", "D1", "D2", "D3") + run.recorder.holdUntilBegun(t, "K", "D2") + run.keep("K") + run.recorder.outputByRun["D2"] = []fakeCompilerOutput{failingCompilerOutput("D2"), {}} + run.recorder.surfacesByRun["D2"] = []string{"", keptSurfaceOf("D2")} + + outcome := run.compile(t) + + if len(outcome.Blocked) != 0 { + t.Errorf("blocked = %v, want none", outcome.Blocked) + } + if !resultOf(t, outcome.Units, "D2").Succeeded { + t.Errorf("D2 = %+v, want the successful second compile", resultOf(t, outcome.Units, "D2")) + } + if !containsLine(compiledNames(outcome.Units), "D3") || run.recorder.runs["D3"] != 1 { + t.Errorf("D3 compiled %d times and results are %v, want one compile reported", + run.recorder.runs["D3"], compiledNames(outcome.Units)) + } +} + +// Verifies a dependent that started before a dependent it references failed is blocked, its result +// thrown away, and the block carried on to the units below it. +func TestCompileUnitsBlocksADependentThatStartedBeforeItsReferenceFailed(t *testing.T) { + run := newOptimisticPlanRun(t, map[string][]string{"D1": {"X", "K"}, "D2": {"X", "D1"}, "D3": {"X", "D2"}}, + []string{"D1", "D2", "D3"}, "X", "K", "D1", "D2", "D3") + run.recorder.holdUntilBegun(t, "K", "D2", "D3") + run.keep("K") + run.fail("D1") + + outcome := run.compile(t) + + assertStrings(t, "results", compiledNames(outcome.Units), []string{"X", "K", "D1"}) + if len(resultOf(t, outcome.Units, "D1").Diagnostics) == 0 { + t.Error("expected D1's errors to be reported") + } + assertStrings(t, "blocked", outcome.Blocked, []string{"D2", "D3"}) + if outcome.Skipped != 0 { + t.Errorf("skipped = %d, want 0", outcome.Skipped) + } + if run.recorder.runs["D2"] != 1 || run.recorder.runs["D3"] != 1 { + t.Errorf("D2 and D3 compiled %d and %d times, want once each before the failure was known", + run.recorder.runs["D2"], run.recorder.runs["D3"]) + } +} + +// Verifies a dependent that assumed a reference later skipped - because everything that reference +// reads kept its surface - is settled with the compile it started early. +func TestCompileUnitsSettlesADependentWhoseAssumedReferenceWasSkipped(t *testing.T) { + run := newOptimisticPlanRun(t, map[string][]string{"R": {"K"}, "U": {"X", "R"}}, + []string{"R", "U"}, "X", "K", "R", "U") + run.recorder.holdUntilBegun(t, "K", "U") + run.keep("K") + + outcome := run.compile(t) + + assertStrings(t, "results", compiledNames(outcome.Units), []string{"X", "K", "U"}) + if outcome.Skipped != 1 || len(outcome.Blocked) != 0 { + t.Errorf("skipped = %d and blocked = %v, want 1 and none", outcome.Skipped, outcome.Blocked) + } + if run.recorder.runs["U"] != 1 { + t.Errorf("U compiled %d times, want 1", run.recorder.runs["U"]) + } + assertStrings(t, "units finished when U started", sortedNames(run.recorder.finishedWhen["U"]), []string{"X"}) + assertStrings(t, "U assumed", resultOf(t, outcome.Units, "U").AssumedReferences, []string{"R"}) +} + +// Verifies a dependent that assumed a reference later blocked by an error further up is blocked +// too, with its result thrown away and the error that caused it still reported. +func TestCompileUnitsBlocksADependentWhoseAssumedReferenceWasBlocked(t *testing.T) { + run := newOptimisticPlanRun(t, map[string][]string{"R": {"A"}, "U": {"X", "R"}}, + []string{"R", "U"}, "X", "A", "R", "U") + run.recorder.holdUntilBegun(t, "A", "U") + run.fail("A") + + outcome := run.compile(t) + + assertStrings(t, "results", compiledNames(outcome.Units), []string{"X", "A"}) + if len(resultOf(t, outcome.Units, "A").Diagnostics) == 0 { + t.Error("expected A's errors to be reported") + } + assertStrings(t, "blocked", outcome.Blocked, []string{"R", "U"}) + if run.recorder.runs["U"] != 1 { + t.Errorf("U compiled %d times, want 1", run.recorder.runs["U"]) + } +} + +// Verifies an assembly selected for its own sources that started before a dependent it references +// finished is compiled again, against this run's output, when that dependent changed its surface. +func TestCompileUnitsCompilesAnEditedAssemblyAgainWhenAnAssumedReferenceChangedItsSurface(t *testing.T) { + project, recorder := newOptimisticCachedProject(t, map[string][]string{"D1": {"X", "K"}, "Y": {"X", "D1"}}, + []string{"D1"}, "X", "K", "D1", "Y") + recorder.holdUntilBegun(t, "K", "Y") + recorder.surfaces["K"] = keptSurfaceOf("K") + + results := project.compileOrFail(t, recorder) + + if recorder.runs["Y"] != 2 { + t.Fatalf("Y compiled %d times, want 2", recorder.runs["Y"]) + } + assertReferenceFlags(t, project.writtenResponseFile(t, "Y"+responseFileExtension), + []string{producedReferenceFlag(project.plan, "D1")}, []string{unityReferenceFlag("D1")}) + if again := resultOf(t, results, "Y").CompiledAgainAfter; again != "D1" { + t.Errorf("Y compiled again after %q, want D1", again) + } +} + +// Verifies an assembly selected for its own sources that started before a dependent it references +// failed is blocked, and its result thrown away. +func TestCompileUnitsBlocksAnEditedAssemblyWhoseAssumedReferenceFailed(t *testing.T) { + run := newOptimisticPlanRun(t, map[string][]string{"D1": {"X", "K"}, "Y": {"X", "D1"}}, + []string{"D1"}, "X", "K", "D1", "Y") + run.recorder.holdUntilBegun(t, "K", "Y") + run.keep("K") + run.fail("D1") + + outcome := run.compile(t) + + assertStrings(t, "blocked", outcome.Blocked, []string{"Y"}) + assertStrings(t, "results", compiledNames(outcome.Units), []string{"X", "K", "D1"}) + if run.recorder.runs["Y"] != 1 { + t.Errorf("Y compiled %d times, want 1", run.recorder.runs["Y"]) + } +} + +// newChainRecorder prepares the fake compiler for the chain plan of the cached project, with K +// keeping its surface and still compiling when D2 can start. +func newChainRecorder(t *testing.T) *schedulerRecorder { + recorder := newCachedSchedulerRecorder("X", "K", "D1", "D2") + recorder.holdUntilBegun(t, "K", "D2") + recorder.surfaces["K"] = keptSurfaceOf("K") + + return recorder +} + +// Verifies a dependent whose record may still be replayed once the dependents it references finish +// waits for them instead of starting early, so a second run over the same inputs replays it rather +// than compiling it twice again. +func TestCompileUnitsWaitsForAnAssumedReferenceWhenItsRecordMayStillApply(t *testing.T) { + project, _ := newOptimisticCachedProject(t, chainReferences, []string{"D1", "D2"}, "X", "K", "D1", "D2") + first := newChainRecorder(t) + project.compileOrFail(t, first) + if first.runs["D2"] != 2 { + t.Fatalf("the first run compiled D2 %d times, want 2", first.runs["D2"]) + } + + second := newChainRecorder(t) + results := project.compileOrFail(t, second) + + d2 := resultOf(t, results, "D2") + if !d2.Reused || second.runs["D2"] != 0 || !d2.WaitedForRecord { + t.Errorf("D2 = %+v after %d compiles, want replayed after waiting for its record", d2, second.runs["D2"]) + } + if _, started := second.finishedWhen["D2"]; started { + t.Error("D2 should not have started a compile in the second run") + } +} + +// Verifies a dependent whose record can no longer be replayed - a reference that already finished +// came out different - starts early again rather than waiting. +func TestCompileUnitsStartsADependentWhenItsRecordCannotApply(t *testing.T) { + project, _ := newOptimisticCachedProject(t, chainReferences, []string{"D1", "D2"}, "X", "K", "D1", "D2") + project.compileOrFail(t, newChainRecorder(t)) + + project.editSource(t, "X", "class X { int Added; }") + second := newChainRecorder(t) + second.surfaces["X"] = "surface X again" + results := project.compileOrFail(t, second) + + d2 := resultOf(t, results, "D2") + if second.runs["D2"] != 2 || d2.WaitedForRecord || d2.Reused { + t.Errorf("D2 = %+v after %d compiles, want compiled twice without waiting", d2, second.runs["D2"]) + } +} + +// Verifies the record of a compile that started early, against a reference that then kept its +// surface, is replayed by the next run, whose key reads that reference the same way. +func TestCompileUnitsReplaysADependentStartedBeforeItsReferencesFinished(t *testing.T) { + project, _ := newOptimisticCachedProject(t, chainReferences, []string{"D1", "D2"}, "X", "K", "D1", "D2") + first := newChainRecorder(t) + first.surfaces["D1"] = keptSurfaceOf("D1") + firstResults := project.compileOrFail(t, first) + if first.runs["D2"] != 1 { + t.Fatalf("the first run compiled D2 %d times, want 1", first.runs["D2"]) + } + assertStrings(t, "D2 assumed", resultOf(t, firstResults, "D2").AssumedReferences, []string{"D1"}) + + second := newChainRecorder(t) + second.surfaces["D1"] = keptSurfaceOf("D1") + results := project.compileOrFail(t, second) + + if d2 := resultOf(t, results, "D2"); !d2.Reused || second.runs["D2"] != 0 { + t.Errorf("D2 = %+v after %d compiles, want replayed", d2, second.runs["D2"]) + } +} + +// Verifies an edited assembly large enough for the changed-files check is checked on its changed +// files when it starts before a dependent it references finishes, assuming that dependent kept +// Unity's surface the way its baseline read it. +func TestCompileUnitsFastChecksAnEditedAssemblyStartedBeforeItsReferencesFinish(t *testing.T) { + project := newCachedSchedulerProject(t, map[string][]string{ + "Gamma": {"Alpha", "K"}, "Beta": {"Alpha", "Gamma"}, + }, "Alpha", "K", "Gamma", "Beta") + markSelectedAsDependent(t, project.plan, "Gamma") + sources := make([]string, 0, fastPathMinimumSources) + for index := 0; index < fastPathMinimumSources; index++ { + source := fmt.Sprintf("Assets/Beta/File%03d.cs", index) + project.writeFile(t, source, bodyContent(index, "body")) + sources = append(sources, source) + } + project.plan.Units[indexOfUnit(t, project.plan, "Beta")].Sources = sources + worker := newFakeFastCheckWorker() + var current *schedulerRecorder + worker.onCheck = func() { current.markBegun("Beta") } + keptRecorder := func() *schedulerRecorder { + recorder := newCachedSchedulerRecorder("Alpha", "K", "Gamma", "Beta") + recorder.holdUntilBegun(t, "K", "Beta") + recorder.surfaces["Alpha"] = keptSurfaceOf("Alpha") + recorder.surfaces["K"] = keptSurfaceOf("K") + recorder.surfaces["Gamma"] = keptSurfaceOf("Gamma") + current = recorder + + return recorder + } + compileWithFastPath(t, project, worker, keptRecorder(), "Alpha", "K", "Gamma", "Beta") + if !project.hasBaselineOf("Beta") { + t.Fatal("expected the full compile of Beta to record a baseline") + } + + // Why K is edited as well: it then compiles again, slowly, so Gamma is still waiting on it when + // Beta can start. A replayed K would let Gamma finish first. + project.editSource(t, "K", "class K { void Body() { } }") + project.writeFile(t, "Assets/Beta/File007.cs", bodyContent(7, "edited body")) + checksBefore := worker.checks + outcome := compileWithFastPath(t, project, worker, keptRecorder(), "Alpha", "K", "Gamma", "Beta") + + beta := resultOf(t, outcome.Units, "Beta") + if !beta.FastChecked || beta.FastPathFallbackReason != "" { + t.Fatalf("expected Beta to be checked on its changed files, got %+v", beta) + } + assertStrings(t, "Beta assumed", beta.AssumedReferences, []string{"Gamma"}) + if checks := worker.checks - checksBefore; checks != 1 { + t.Errorf("the worker checked %d times, want 1", checks) + } +} + +// Verifies a plan whose references never let a unit become ready - a cycle - ends the run with an +// error naming the units left over, instead of an empty success. +func TestCompileUnitsReportsAPlanItCannotFinish(t *testing.T) { + plan := newSchedulerPlan(map[string][]string{"A": {"B"}, "B": {"A"}}, "A", "B") + compiler := newSchedulerCompiler(t, newSchedulerRecorder(0)) + + _, err := compileUnits(context.Background(), compiler, plan, 2) + + if err == nil { + t.Fatal("expected the run to fail") + } + if !strings.Contains(err.Error(), "A") || !strings.Contains(err.Error(), "B") { + t.Errorf("error = %v, want it to name A and B", err) + } +} + +// Verifies a unit queued early that a reference with errors then blocks keeps waiting for the other +// references it has until they finish, rather than being decided while one of them still compiles: +// U is queued behind B with S still compiling when R's failure blocks it. +func TestCompileUnitsDecidesABlockedUnitQueuedEarlyOnlyOnceItsReferencesFinish(t *testing.T) { + run := newOptimisticPlanRun(t, map[string][]string{"R": {"X"}, "B": {"X"}, "S": {"X"}, "U": {"X", "R", "S"}}, + []string{"R", "B", "S", "U"}, "X", "R", "B", "S", "U") + run.jobs = 2 + run.fail("R") + run.recorder.holdByUnit["B"] = 20 * time.Millisecond + run.recorder.holdByUnit["S"] = 80 * time.Millisecond + + outcome := run.compile(t) + + assertStrings(t, "blocked", outcome.Blocked, []string{"U"}) +} + +// Verifies a unit queued early that becomes ready while it still waits for a free job is queued +// once and compiled once: D is queued early behind B, and A finishes before a job frees up. +func TestCompileUnitsQueuesAUnitOnceWhenItsLastReferenceFinishesWhileItWaitsForAJob(t *testing.T) { + run := newOptimisticPlanRun(t, map[string][]string{"A": {"X"}, "B": {"X"}, "D": {"X", "A"}}, + []string{"A", "B", "D"}, "X", "A", "B", "D") + run.jobs = 1 + + run.compile(t) + + if run.recorder.runs["D"] != 1 { + t.Errorf("D compiled %d times, want 1", run.recorder.runs["D"]) + } +} diff --git a/cli/dispatcher/internal/compilecheck/scheduler_settle.go b/cli/dispatcher/internal/compilecheck/scheduler_settle.go new file mode 100644 index 000000000..9bffbb557 --- /dev/null +++ b/cli/dispatcher/internal/compilecheck/scheduler_settle.go @@ -0,0 +1,277 @@ +package compilecheck + +import ( + "fmt" + "strings" + "time" +) + +// unitProgress is where each unit of a run stands on its way to a final state. +type unitProgress struct { + // queued marks a unit waiting in ready, started one whose compile has been launched at least + // once, finished one whose latest compile is back but not yet decided on, and final one whose + // final state is decided. + queued, started, finished, final []bool + // assumed lists, per unit, the references that had no final state when its latest compile + // started, and that it read from Unity's build on the assumption that they keep its surface. + assumed [][]int + // stale marks a unit whose latest compile assumed a reference that then changed its surface, + // and staleCause names the first such reference, or -1. + stale []bool + staleCause []int + // deferred marks a unit that did not start early because its record might still be replayed. + deferred []bool + // pendingKept holds the surface verdict of a unit's latest compile until its final state is + // decided, and discarded how long the compile it threw away took. + pendingKept []bool + discarded []time.Duration +} + +// newUnitProgress prepares the progress of count units, none of which has started. +func newUnitProgress(count int) unitProgress { + progress := unitProgress{ + queued: make([]bool, count), + started: make([]bool, count), + finished: make([]bool, count), + final: make([]bool, count), + assumed: make([][]int, count), + stale: make([]bool, count), + staleCause: make([]int, count), + deferred: make([]bool, count), + pendingKept: make([]bool, count), + discarded: make([]time.Duration, count), + } + for index := range progress.staleCause { + progress.staleCause[index] = -1 + } + + return progress +} + +// enqueue puts a unit at the end of the ready queue. +func (state *schedule) enqueue(index int) { + state.queued[index] = true + state.ready = append(state.ready, index) +} + +// takeNext removes the next unit to start from the ready queue. +func (state *schedule) takeNext() int { + index := state.ready[0] + state.ready = state.ready[1:] + state.queued[index] = false + + return index +} + +// mayStartEarly reports whether a unit with references still lacking a final state may start before +// them: it has to compile whatever they turn out to be, every reference still missing is a dependent +// rather than one selected for its own sources, and nothing has ruled it out. +// Why a reference selected for its own sources is waited for: its sources changed, so it is likely +// to change its surface, and starting before it would mostly compile against the wrong file. +// Why a dependent nothing changed under waits too: it may still be skipped once the rest finish. +func (state *schedule) mayStartEarly(index int) bool { + mustCompile := state.ownSources[index] || state.changedInputs[index] > 0 + + return mustCompile && state.pendingOwn[index] == 0 && !state.blocked[index] && !state.deferred[index] +} + +// offer queues a unit that has not started when it may start now: when every reference has a final +// state, or when it may start early and its record could not be replayed by waiting. +// Why the record is asked about before starting early: a compile overwrites the unit's record, so +// starting early would throw away a record the same inputs replay once the references finish, and +// every later run over those inputs would compile the unit twice again. Once the record says no it +// says no for good - fewer unknown references only make it stricter - so the answer is not asked again. +func (run *schedulerRun) offer(index int) { + state := run.state + if state.started[index] || state.queued[index] || state.final[index] { + return + } + if state.pending[index] == 0 { + state.enqueue(index) + + return + } + if !state.mayStartEarly(index) { + return + } + unit, unknown := run.startingUnit(index) + if run.compiler.recordMayStillApply(run.plan, unit, run.namedUnits(unknown)) { + state.deferred[index] = true + + return + } + state.enqueue(index) +} + +// releaseAndOffer tells the units waiting on one that just got its final state, and queues those that +// may start now. +func (run *schedulerRun) releaseAndOffer(index int, changed bool) { + for _, dependent := range run.state.release(index, changed) { + run.offer(dependent) + } +} + +// startAndSettle starts what is ready and decides the final state of what finished, until neither +// moves anything. +// Why the two alternate: a skip decided while starting units gives a reference its final state, +// which can let a unit that already finished be decided, and deciding one can make others ready. +func (run *schedulerRun) startAndSettle(jobs int) error { + for { + if err := run.startReadyUnits(jobs); err != nil { + return err + } + settled, err := run.settleFinished() + if err != nil { + return err + } + if !settled { + return nil + } + } +} + +// settleFinished decides the final state of every finished unit whose references all have one, until +// none is left, and reports whether it decided anything. +func (run *schedulerRun) settleFinished() (bool, error) { + state := run.state + progressed := false + for settled := true; settled; { + settled = false + for index := range run.plan.Units { + if !state.finished[index] || state.final[index] || state.pending[index] != 0 { + continue + } + settled = true + progressed = true + if err := run.settle(index); err != nil { + return progressed, err + } + } + } + + return progressed, nil +} + +// settle decides what a finished unit's latest compile counts for, now that every reference it has +// in the plan has a final state: nothing when one it assumed failed or was blocked, a compile again +// when one it assumed changed its surface, and its result otherwise. +// Why a compile again rather than a correction: the reference assembly it read is the wrong one, and +// what csc reports against the right one cannot be derived from what it reported against Unity's. +func (run *schedulerRun) settle(index int) error { + state := run.state + switch { + case state.blocked[index]: + state.finished[index] = false + if err := run.markFinal(index); err != nil { + return err + } + state.blockDependents(index) + run.releaseAndOffer(index, false) + case state.stale[index]: + state.discarded[index] = run.results[index].Duration + run.results[index] = UnitResult{} + state.finished[index] = false + state.stale[index] = false + state.assumed[index] = nil + state.enqueue(index) + default: + return run.adopt(index) + } + + return nil +} + +// adopt makes a finished unit's latest compile its final state and tells the units below it. +// Why a replayed result blocks the same way a compiled one does: it says the assembly has errors, +// and whether this run learned that from csc or from what the last run recorded changes nothing about +// the reference assembly the units below it would have to read. +func (run *schedulerRun) adopt(index int) error { + state := run.state + result := run.results[index] + result.AssumedReferences = run.namesOf(state.assumed[index]) + result.WaitedForRecord = state.deferred[index] + if cause := state.staleCause[index]; cause >= 0 { + result.CompiledAgainAfter = run.plan.Units[cause].Assembly.AssemblyName + result.DiscardedDuration = state.discarded[index] + } + run.results[index] = result + if err := run.markFinal(index); err != nil { + return err + } + run.compiled[index] = true + state.keptSurface[index] = state.pendingKept[index] + if !result.Succeeded { + state.blockDependents(index) + } + run.releaseAndOffer(index, !state.keptSurface[index]) + + return nil +} + +// markFinal gives a unit its final state, which every unit may get only once every reference it has +// in the plan has one. +// Why a breach is an error rather than ignored: a unit decided early tells the units below it what +// it turned out as before that is settled, and the run then reports results nobody can trust. As an +// error it stops the run the way a plan it cannot finish does, after the running compiles return. +func (run *schedulerRun) markFinal(index int) error { + if run.state.pending[index] != 0 { + return fmt.Errorf("compile-check finished scheduling %s before every assembly it references finished", + run.plan.Units[index].Assembly.AssemblyName) + } + run.state.final[index] = true + + return nil +} + +// unfinishedError reports the units a run that ran out of work never decided on, or nil when there +// are none. +// Why it is an error: only references that wait on each other leave units behind, and returning +// without them would report a clean run that never compiled them. +func (run *schedulerRun) unfinishedError() error { + left := []string{} + for index, final := range run.state.final { + if !final { + left = append(left, run.plan.Units[index].Assembly.AssemblyName) + } + } + if len(left) == 0 { + return nil + } + + return fmt.Errorf("compile-check could not finish scheduling %d assemblies: %s", + len(left), strings.Join(left, ", ")) +} + +// namesOf names the given units of the plan, in the order given; nil for none. +func (run *schedulerRun) namesOf(indices []int) []string { + if len(indices) == 0 { + return nil + } + names := make([]string, 0, len(indices)) + for _, index := range indices { + names = append(names, run.plan.Units[index].Assembly.AssemblyName) + } + + return names +} + +// namedUnits is the set of the names of the given units of the plan. +func (run *schedulerRun) namedUnits(indices []int) map[string]bool { + names := make(map[string]bool, len(indices)) + for _, index := range indices { + names[run.plan.Units[index].Assembly.AssemblyName] = true + } + + return names +} + +// containsIndex reports whether indices holds index. +func containsIndex(indices []int, index int) bool { + for _, candidate := range indices { + if candidate == index { + return true + } + } + + return false +} diff --git a/cli/dispatcher/internal/compilecheck/scheduler_test.go b/cli/dispatcher/internal/compilecheck/scheduler_test.go index a562f9659..c73faf78a 100644 --- a/cli/dispatcher/internal/compilecheck/scheduler_test.go +++ b/cli/dispatcher/internal/compilecheck/scheduler_test.go @@ -62,6 +62,74 @@ type schedulerRecorder struct { // run kills it mid-compile: whatever it had already printed, plus an exit error. Without this a // test can only produce the tidy failure of a process that never ran. killedUnits map[string]bool + // outputByRun holds, per unit, what the n-th invocation of it prints and exits with. An + // invocation past its end falls back to output. + outputByRun map[string][]fakeCompilerOutput + // surfacesByRun holds, per unit, the reference assembly the n-th invocation of it writes; an + // empty one writes none. An invocation past its end falls back to surfaces. + surfacesByRun map[string][]string + // begun names the units whose compile or changed-files check has begun. + begun map[string]bool + // heldUntilBegun holds, per unit, the units its fake invocation waits to see begun before it + // finishes, so a test can rely on those starting while it still runs instead of on a hold long + // enough under every load. gatesReleased lets every waiting invocation finish. + heldUntilBegun map[string][]string + gatesReleased bool +} + +// gateLimit is how long a held invocation waits for the units it waits on before it finishes anyway. +// Why it finishes rather than fails: the test's own assertions then say what started in which +// order, which says more than a timeout would. +const gateLimit = 10 * time.Second + +// holdUntilBegun makes the fake invocation of unit finish only once every named unit has begun, or +// gateLimit has passed. Every invocation still waiting is let go when the test ends. +func (recorder *schedulerRecorder) holdUntilBegun(t *testing.T, unit string, names ...string) { + t.Helper() + recorder.mutex.Lock() + recorder.heldUntilBegun[unit] = names + recorder.mutex.Unlock() + t.Cleanup(func() { + recorder.mutex.Lock() + recorder.gatesReleased = true + recorder.mutex.Unlock() + }) +} + +// markBegun records that the named unit has begun, for a unit checked on its changed files, which +// never reaches the fake compiler. +func (recorder *schedulerRecorder) markBegun(name string) { + recorder.mutex.Lock() + recorder.begun[name] = true + recorder.mutex.Unlock() +} + +// waitForGate returns once every unit the named one waits on has begun, the gates were released, or +// gateLimit has passed. +func (recorder *schedulerRecorder) waitForGate(name string) { + deadline := time.Now().Add(gateLimit) + for time.Now().Before(deadline) { + if recorder.gateOpen(name) { + return + } + time.Sleep(time.Millisecond) + } +} + +// gateOpen reports whether the named unit no longer has to wait. +func (recorder *schedulerRecorder) gateOpen(name string) bool { + recorder.mutex.Lock() + defer recorder.mutex.Unlock() + if recorder.gatesReleased { + return true + } + for _, waited := range recorder.heldUntilBegun[name] { + if !recorder.begun[waited] { + return false + } + } + + return true } // fakeCompilerOutput is what one fake invocation prints and exits with. @@ -73,16 +141,20 @@ type fakeCompilerOutput struct { // newSchedulerRecorder prepares a recorder whose units each take the same time to compile. func newSchedulerRecorder(hold time.Duration) *schedulerRecorder { return &schedulerRecorder{ - hold: hold, - holdByUnit: map[string]time.Duration{}, - started: map[string]bool{}, - surfaces: map[string]string{}, - assemblies: map[string]string{}, - output: map[string]fakeCompilerOutput{}, - killedUnits: map[string]bool{}, - runs: map[string]int{}, - finished: map[string]bool{}, - finishedWhen: map[string][]string{}, + hold: hold, + holdByUnit: map[string]time.Duration{}, + started: map[string]bool{}, + surfaces: map[string]string{}, + assemblies: map[string]string{}, + output: map[string]fakeCompilerOutput{}, + killedUnits: map[string]bool{}, + runs: map[string]int{}, + finished: map[string]bool{}, + finishedWhen: map[string][]string{}, + outputByRun: map[string][]fakeCompilerOutput{}, + surfacesByRun: map[string][]string{}, + begun: map[string]bool{}, + heldUntilBegun: map[string][]string{}, } } @@ -93,6 +165,8 @@ func (recorder *schedulerRecorder) runner() CommandRunner { recorder.mutex.Lock() recorder.started[name] = true recorder.runs[name]++ + run := recorder.runs[name] + recorder.begun[name] = true recorder.running++ if recorder.running > recorder.maxRunning { recorder.maxRunning = recorder.running @@ -109,6 +183,9 @@ func (recorder *schedulerRecorder) runner() CommandRunner { failing := recorder.failingUnit == name during := recorder.during output := recorder.output[name] + if byRun := recorder.outputByRun[name]; run <= len(byRun) { + output = byRun[run-1] + } killed := recorder.killedUnits[name] recorder.mutex.Unlock() @@ -116,8 +193,9 @@ func (recorder *schedulerRecorder) runner() CommandRunner { during(name) } time.Sleep(hold) + recorder.waitForGate(name) - recorder.writeReferenceAssembly(cmd, name) + recorder.writeReferenceAssembly(cmd, name, run) recorder.writeAssembly(cmd, name) recorder.mutex.Lock() @@ -159,11 +237,14 @@ func (recorder *schedulerRecorder) writeAssembly(cmd *exec.Cmd, name string) { writeBesideResponseFile(cmd, name+assemblyExtension, content) } -// writeReferenceAssembly writes the reference assembly this fake invocation is set up to produce, -// beside the response file it was given, which is where csc writes it too. -func (recorder *schedulerRecorder) writeReferenceAssembly(cmd *exec.Cmd, name string) { +// writeReferenceAssembly writes the reference assembly the run-th invocation of the unit is set up to +// produce, beside the response file it was given, which is where csc writes it too. +func (recorder *schedulerRecorder) writeReferenceAssembly(cmd *exec.Cmd, name string, run int) { recorder.mutex.Lock() surface, produces := recorder.surfaces[name] + if byRun := recorder.surfacesByRun[name]; run <= len(byRun) { + surface, produces = byRun[run-1], byRun[run-1] != "" + } recorder.mutex.Unlock() if !produces { return diff --git a/cli/dispatcher/internal/dispatcher/compile_check_vibe_log.go b/cli/dispatcher/internal/dispatcher/compile_check_vibe_log.go index fbc7df274..3d699299b 100644 --- a/cli/dispatcher/internal/dispatcher/compile_check_vibe_log.go +++ b/cli/dispatcher/internal/dispatcher/compile_check_vibe_log.go @@ -136,25 +136,48 @@ func compileCheckVibeReasons(reasons []compileCheckFastPathFallback) []map[strin return entries } -// compileCheckVibeUnits lists how long each unit this run compiled or checked took. +// compileCheckVibeUnits lists how long each unit this run compiled or checked took, and how it was +// scheduled when that was out of the ordinary: the references it assumed kept Unity's surface, the +// one that made it compile again and the time the compile it threw away took, and that it waited +// for a record that then did not apply - a unit whose record applied is replayed and left out. // Why replayed units are left out: they took no work, and their durations would only hide which // units the run spent its time on. +// Why the scheduling keys appear only when they say something: most units carry none of them, and a +// line of empty values would hide the few that do. func compileCheckVibeUnits(units []compilecheck.UnitResult) []map[string]any { entries := make([]map[string]any, 0, len(units)) for _, unit := range units { if unit.Reused || unit.FastCheckReused { continue } - entries = append(entries, map[string]any{ + entry := map[string]any{ "assembly": unit.Assembly, "duration_ms": unit.Duration.Milliseconds(), "succeeded": unit.Succeeded, - }) + } + addCompileCheckVibeScheduling(entry, unit) + entries = append(entries, entry) } return entries } +// addCompileCheckVibeScheduling adds to a units entry the scheduling keys that apply to the unit. +func addCompileCheckVibeScheduling(entry map[string]any, unit compilecheck.UnitResult) { + if len(unit.AssumedReferences) > 0 { + entry["assumed_kept"] = unit.AssumedReferences + } + if unit.CompiledAgainAfter != "" { + entry["compiled_again_after"] = unit.CompiledAgainAfter + } + if unit.DiscardedDuration > 0 { + entry["discarded_ms"] = unit.DiscardedDuration.Milliseconds() + } + if unit.WaitedForRecord { + entry["waited_for_record"] = true + } +} + // compileCheckVibeSurfaceChecks lists every unit whose surface the worker, or its record of the same // comparison, settled: what it answered and how long asking took. // Why replayed units are kept here, unlike in units: a replayed unit is compared just the same, and diff --git a/cli/dispatcher/internal/dispatcher/compile_check_vibe_log_test.go b/cli/dispatcher/internal/dispatcher/compile_check_vibe_log_test.go index e3dab053d..df02dd33c 100644 --- a/cli/dispatcher/internal/dispatcher/compile_check_vibe_log_test.go +++ b/cli/dispatcher/internal/dispatcher/compile_check_vibe_log_test.go @@ -209,3 +209,32 @@ func TestCompileCheckVibeLogRecordsAnEditorResolutionFailure(t *testing.T) { complete := assertCompileCheckVibeRun(t, readCompileCheckVibeLog(t, projectRoot)) assertVibeContextJSON(t, complete, "outcome", `"failed"`) } + +// Verifies the units entries say which references a unit assumed kept Unity's surface, which one +// made it compile again and how long the discarded compile took, and that it waited for a record, +// each only on the units it applies to. +func TestCompileCheckVibeLogRecordsUnitsCompiledAgain(t *testing.T) { + t.Setenv(vibelog.CLIVibeLogEnvName, "1") + projectRoot := t.TempDir() + result := compilecheck.Result{Units: []compilecheck.UnitResult{ + {Assembly: "Alpha", Succeeded: true, Duration: 100 * time.Millisecond}, + { + Assembly: "Beta", Succeeded: true, Duration: 200 * time.Millisecond, + AssumedReferences: []string{"Gamma", "Delta"}, + }, + { + Assembly: "Epsilon", Succeeded: true, Duration: 300 * time.Millisecond, + CompiledAgainAfter: "Gamma", DiscardedDuration: 50 * time.Millisecond, WaitedForRecord: true, + }, + }} + + logRun := startCompileCheckVibeLog(projectRoot, compileCheckOptions{}) + logRun.completed(buildCompileCheckResponse(result, projectRoot), result) + + complete := assertCompileCheckVibeRun(t, readCompileCheckVibeLog(t, projectRoot)) + assertVibeContextJSON(t, complete, "units", + `[{"assembly":"Alpha","duration_ms":100,"succeeded":true},`+ + `{"assembly":"Beta","assumed_kept":["Gamma","Delta"],"duration_ms":200,"succeeded":true},`+ + `{"assembly":"Epsilon","compiled_again_after":"Gamma","discarded_ms":50,"duration_ms":300,`+ + `"succeeded":true,"waited_for_record":true}]`) +} diff --git a/docs/adr/0016-compile-check-starts-dependents-before-the-dependents-they-reference-finish.md b/docs/adr/0016-compile-check-starts-dependents-before-the-dependents-they-reference-finish.md new file mode 100644 index 000000000..4cce6f387 --- /dev/null +++ b/docs/adr/0016-compile-check-starts-dependents-before-the-dependents-they-reference-finish.md @@ -0,0 +1,80 @@ +# Compile Check Starts Dependents Before the Dependents They Reference Finish + +Date: 2026-10-15 + +## Decision + +`uloop compile-check` starts an assembly that has to compile - one selected for its own sources, +or a dependent at least one of whose finished references changed its public surface - as soon as +every assembly it references that was selected for its own sources has finished. It does not wait +for the dependents it references that are still compiling. For those it reads Unity's reference +assembly, assuming they keep Unity's public surface. + +- An assembly's final state is decided only once every assembly it references in the plan has + one. When every assumption held, the compile it started early is its result. When an assumed + reference changed its surface, it is compiled again, against this run's output for that + reference. When an assumed reference failed or was blocked, the assembly is blocked and its + result is dropped. The errors and the surface verdict of a dropped result decide nothing for the + assemblies below it. +- An assembly is compiled at most twice per run: the second compile starts only once every + reference has its final state, so it assumes nothing. +- An assembly whose recorded result may still be replayed once the dependents it references + finish does not start early; it waits for them. A compile overwrites the record, so starting + early would throw away a record the same inputs replay, and every run over those inputs would + compile it twice. The record keeps, beside its input key, a digest of every input except the + references to project assemblies and the identity of each of those references, so the check + compares everything but the references still compiling, without reading the sources when a + finished reference already differs. +- An assembly still waits for references selected for their own sources (they are likely to + change their surface), and a dependent none of whose finished references changed still waits + (it may still be skipped). `--all` selects every assembly for its own sources, so nothing starts + early there. + +## Context + +On a project with 561 assemblies, adding a public member to an assembly that 67 others reference +compiled all 68 and took 35 to 43 seconds. The edited assembly took about 10.5 seconds; the 67 +dependents took 57 to 71 seconds of CPU between them but 25 to 32 seconds of wall time with eight +jobs, because they reference each other through 354 references up to ten levels deep. Every +dependent waited for its references to finish, so the critical path through the dependents - 31 +to 37 seconds - was the wall time. More jobs did not help: 12 and 16 jobs saved 2 to 5 seconds, +and 24 jobs took almost twice as long. + +In all nine of those runs, the only reference assembly that differed from Unity's build was the +edited assembly's: the run's surface checks named one assembly each time. Every dependent waited +for the dependents it references only to read Unity's reference assembly for them anyway. + +Simulating the schedule with the measured unit times puts the new critical path at 20 to 25 +seconds. The floor is the edited assembly plus the largest dependent, which can only start after +it. + +## Considered Options + +- **Start a dependent when the dependents it references have handed their sources to csc, rather + than when they finish.** It would remove the wasted early compile of a run that replays the + references, but that waste happens only when a replay and a changed surface coincide, and only + then on repeated runs. Not now. +- **Stop a running compile as soon as an assumption fails.** It needs a per-assembly cancel, and + the compile it saves is at most one per assembly per run. Not now. +- **Write the early compile's outputs and record somewhere else and move them into place when they + are kept.** It would protect the record without the waiting rule, but where the outputs live is + assumed by the compile, the surface verdict and the changed-files baseline alike, so it moves + many parts, and the early compile would still run on every repeated run. + +## Limits + +- An assembly selected for its own sources has no record that can still apply (its sources + changed), so it starts early. If its changed-files check falls back to a full compile and an + assumed reference then changes its surface, the full compile removes its changed-files baseline + and the compile again records a new one. The loss is only for running the same state again with + a changed dependent below an edited assembly: a changed-files check becomes two full compiles. + It did not occur in the measured runs. + +## Revisit When + +- On a real project, more than one in ten of the assemblies that started early carry + `compiled_again_after` in the VibeLog. Then narrow what is assumed, or stop starting early. +- More than one in ten of the assemblies that started early, or waited instead, carry + `waited_for_record` - a wait for a record that then did not apply. Then revisit the record check. +- A report shows the changed-files baseline of an edited assembly lost this way. Then extend the + record check to the baseline. diff --git a/docs/compile-check.md b/docs/compile-check.md index 55192b3dd..b215b4cbd 100644 --- a/docs/compile-check.md +++ b/docs/compile-check.md @@ -97,11 +97,22 @@ references, scripting defines and analyzers. `compile-check` replays those respo reference that was added to one, invalidate the recorded build. The run then stops with `COMPILE_CHECK_UNITY_BUILD_REQUIRED` rather than reporting diagnostics for a configuration the project no longer has. -5. **Compile in dependency order** and parse the compiler's diagnostics into JSON. An assembly starts - as soon as every assembly it references that this run also compiles has finished, so independent - assemblies compile at the same time. `--jobs ` caps how many run at once; the default is half - the machine's CPUs and never less than one, because one `csc` process already keeps two to three - cores busy on its own. `--jobs 1` compiles the assemblies one after another. +5. **Compile in dependency order** and parse the compiler's diagnostics into JSON. An assembly + starts once every assembly it references that this run also compiles has finished, so + independent assemblies compile at the same time. An assembly selected for its own sources, or a + dependent that is already known to need compiling, starts sooner: as soon as every assembly it + references that was selected for its own sources has finished. The dependents it references + that are still compiling are assumed to keep Unity's public surface, so it reads Unity's + reference assembly for them. When one of them turns out to have changed its surface, the + assembly is compiled again after all of them finished; when one of them fails, the assembly is + blocked. An assembly is compiled at most twice per run. An assembly whose recorded result may + still apply once those dependents finish waits for them instead, so a run over the same inputs + still replays it. `assumed_kept` and `compiled_again_after` in the VibeLog's `units` say which + happened. A unit whose record applied after the wait is counted under `reused` and does not + appear in `units`; `waited_for_record` marks a unit that waited for a record that then did not + apply. `--jobs ` caps how many run at once; the default is half the machine's CPUs and never + less than one, because one `csc` process already keeps two to three cores busy on its own. + `--jobs 1` compiles the assemblies one after another. The reported order does not depend on the job count: results are collected in dependency order whatever finishes first. An assembly that fails to compile stops the run at that point of the tree: it wrote no reference assembly, so everything below it has nothing to compile against and diff --git a/docs/vibe-logs.md b/docs/vibe-logs.md index 98a1794d6..cdcc4e728 100644 --- a/docs/vibe-logs.md +++ b/docs/vibe-logs.md @@ -280,7 +280,7 @@ because there is no project to write into. | `operation` | Written | `context` | |---|---|---| | `cli_compile_check_start` | once the project is found | `command`, `all`, `full`, `jobs`, `project_identity` | -| `cli_compile_check_complete` (`INFO`; `WARNING` when the run found compile errors; `ERROR` when it could not finish) | on every way out of a run that wrote the start entry | `command`, `outcome` (`succeeded`, `errors`, or `failed`), `duration_ms`; for `failed`, `error` and `error_code`; otherwise `error_count`, `warning_count`, `compiled`, `reused`, `fast_checked`, `blocked` (assembly names, as in the response), `skipped_count`, `fast_checks` (`assembly`, `reused`, `changed_file_count`), `fallbacks` and `baseline_notes` (`assembly`, `reason`), `units` (`assembly`, `duration_ms`, `succeeded` of each assembly the run compiled or checked; replayed ones are left out), and `surface_checks` (`assembly`, `verdict`, `detail`, `duration_ms`, `from_record` of each assembly whose rebuilt reference assembly differed in bytes from Unity's and was compared by the worker or taken from its record, replayed ones included) | +| `cli_compile_check_complete` (`INFO`; `WARNING` when the run found compile errors; `ERROR` when it could not finish) | on every way out of a run that wrote the start entry | `command`, `outcome` (`succeeded`, `errors`, or `failed`), `duration_ms`; for `failed`, `error` and `error_code`; otherwise `error_count`, `warning_count`, `compiled`, `reused`, `fast_checked`, `blocked` (assembly names, as in the response), `skipped_count`, `fast_checks` (`assembly`, `reused`, `changed_file_count`), `fallbacks` and `baseline_notes` (`assembly`, `reason`), `units` (`assembly`, `duration_ms`, `succeeded` of each assembly the run compiled or checked; replayed ones are left out; `assumed_kept` names the references it started ahead of, assuming they kept Unity's surface, `compiled_again_after` the one whose changed surface made it compile again and `discarded_ms` how long the compile it threw away took, and `waited_for_record` says it waited for its references for a record that then did not apply - each only when it applies), and `surface_checks` (`assembly`, `verdict`, `detail`, `duration_ms`, `from_record` of each assembly whose rebuilt reference assembly differed in bytes from Unity's and was compared by the worker or taken from its record, replayed ones included) | - Unlike the tool-command entries, the complete entry holds the run's error message and fallback reasons: they can name assemblies and files of the project, which the command's own output prints