diff --git a/cli/dispatcher/internal/compilecheck/compiler.go b/cli/dispatcher/internal/compilecheck/compiler.go index 28182bba0..762823240 100644 --- a/cli/dispatcher/internal/compilecheck/compiler.go +++ b/cli/dispatcher/internal/compilecheck/compiler.go @@ -113,6 +113,17 @@ type Compiler struct { // compares the two. Why it can be replaced: the tests have to see which units the run compares at // all, and a byte comparison leaves nothing behind to count. compareSurface func(projectRoot string, plan BuildPlan, unit CompileUnit) SurfaceVerdict + // beforeCompilerWork is called right before a unit compiles in full or the worker checks its + // changed files; nil calls nothing. Why: a run that does either reads what it may need later while + // that work runs, and one that only replays never does. + beforeCompilerWork func() +} + +// startCompilerWork calls the hook set for the moment a unit's compile or check begins, if any. +func (c Compiler) startCompilerWork() { + if c.beforeCompilerWork != nil { + c.beforeCompilerWork() + } } // surfaceVerdict says whether compiling this unit left its reference assembly showing its dependents diff --git a/cli/dispatcher/internal/compilecheck/fast_path.go b/cli/dispatcher/internal/compilecheck/fast_path.go index 0401dab08..00339d365 100644 --- a/cli/dispatcher/internal/compilecheck/fast_path.go +++ b/cli/dispatcher/internal/compilecheck/fast_path.go @@ -140,6 +140,7 @@ func (runner *fastPathRunner) check( return fastPathAttempt{Used: true, Result: fastCheckedUnitResult(unit, recorded, time.Since(startedAt), true)} } + c.startCompilerWork() responseFilePath, err := writeRewrittenResponseFile( c.ProjectRoot, plan, unit, unit.Assembly.AssemblyName+fastCheckResponseFileSuffix, nil) if err != nil { diff --git a/cli/dispatcher/internal/compilecheck/name_index.go b/cli/dispatcher/internal/compilecheck/name_index.go index 0595f9ab9..c1111b0ce 100644 --- a/cli/dispatcher/internal/compilecheck/name_index.go +++ b/cli/dispatcher/internal/compilecheck/name_index.go @@ -9,6 +9,8 @@ import ( "path/filepath" "slices" "strings" + "sync" + "sync/atomic" "time" "unicode" "unicode/utf8" @@ -34,12 +36,16 @@ type NameSkip struct { // NameIndexReport says what reading the identifiers of the units with references in the plan took. type NameIndexReport struct { + // Duration is the time spent reading the generator output and, when they were read, the sources. Duration time.Duration // Units counts the units whose identifiers were read, WithGenerated those whose saved generator // output was read too, and Unreadable those that could not be read and so compile on any change. Units int WithGenerated int Unreadable int + // SourcesRead says whether the run needed the sources, by compiling a unit, by having the worker + // check its changed files, or by asking a verdict for names. + SourcesRead bool } // identifierSet is the identifiers one unit writes. @@ -162,78 +168,112 @@ func readGeneratedIdentifiers(generatedDirectory string) (identifierSet, bool, e return identifiers, true, nil } -// nameIndex reads, in the background, the identifiers of every unit that references another unit of -// the plan, so a reference that changed only names a unit never writes need not make it compile. +// nameIndex reads the identifiers of every unit that references another unit of the plan, so a +// reference that changed only names a unit never writes need not make it compile. // Why every such unit and not only the dependents: a unit selected for its own sources compiles // anyway, but one that started on the assumption that a reference keeps its surface need not compile // again when that reference changed only names it never writes. type nameIndex struct { + projectRoot string + units []CompileUnit sets []identifierSet errs []error withGenerated []bool indexed []bool done chan struct{} - duration time.Duration - started bool + // generatedDuration and sourcesDuration are how long each read took, measured from its own start + // so the time the run spent before asking for the sources is not counted. + generatedDuration time.Duration + sourcesDuration time.Duration + started bool + sourcesOnce sync.Once + sourcesRead atomic.Bool } -// start reads the identifiers of the units marked in wanted, at most once per run. generated holds -// the generator output directory of each unit. The generator output is read before start returns and -// the sources in the background. -// Why the generator output is read first: a unit's compile removes and rewrites that directory, and a -// read racing it would lose the names only the generator wrote. Sources are never removed, and few -// units have saved generator output, so only the sources are worth reading while compiles run. +// unitIdentifiers is what was read of one unit's identifiers. +type unitIdentifiers struct { + set identifierSet + withGenerated bool + err error +} + +// start reads the generator output of the units marked in wanted, at most once per run, and leaves +// their sources for readSources. generated holds the generator output directory of each unit. +// Why the generator output is read here, before anything compiles: a unit's compile removes and +// rewrites that directory, and a read racing it would lose the names only the generator wrote. +// Sources are never removed, so they can wait until a run needs them. func (index *nameIndex) start(projectRoot string, units []CompileUnit, generated []string, wanted []bool) { if index.started { return } index.started = true + index.projectRoot = projectRoot + index.units = units index.done = make(chan struct{}) index.indexed = wanted startedAt := time.Now() - type unitNames struct { - set identifierSet - withGenerated bool - err error - } - generatedNames := computeInParallel(len(units), func(position int) unitNames { + generatedNames := computeInParallel(len(units), func(position int) unitIdentifiers { if !wanted[position] { - return unitNames{} + return unitIdentifiers{} } set, withGenerated, err := readGeneratedIdentifiers(generated[position]) - return unitNames{set: set, withGenerated: withGenerated, err: err} + return unitIdentifiers{set: set, withGenerated: withGenerated, err: err} }) - go func() { - defer close(index.done) - results := computeInParallel(len(units), func(position int) unitNames { - names := generatedNames[position] - if !wanted[position] || names.err != nil { + index.keep(generatedNames) + index.generatedDuration = time.Since(startedAt) +} + +// readSources starts reading, in the background, the sources of the units start read the generator +// output of, at most once per run; nothing when start never ran. +// Why the read waits for this call: a run that only replays and asks no verdict for names would +// otherwise spend most of its time reading names it never uses. A run that compiles or checks reads +// them while that runs, and a verdict that needs them waits for them. +// Safe to call from any goroutine. +func (index *nameIndex) readSources() { + if !index.started { + return + } + index.sourcesOnce.Do(func() { + index.sourcesRead.Store(true) + go func() { + defer close(index.done) + startedAt := time.Now() + defer func() { index.sourcesDuration = time.Since(startedAt) }() + index.keep(computeInParallel(len(index.units), func(position int) unitIdentifiers { + names := unitIdentifiers{set: index.sets[position], withGenerated: index.withGenerated[position], err: index.errs[position]} + if !index.indexed[position] || names.err != nil { + return names + } + if err := readSourceIdentifiers(index.projectRoot, index.units[position], names.set); err != nil { + return unitIdentifiers{err: err} + } + return names - } - if err := readSourceIdentifiers(projectRoot, units[position], names.set); err != nil { - return unitNames{err: err} - } + })) + }() + }) +} - return names - }) - index.sets = make([]identifierSet, len(units)) - index.errs = make([]error, len(units)) - index.withGenerated = make([]bool, len(units)) - for position, result := range results { - index.sets[position] = result.set - index.errs[position] = result.err - index.withGenerated[position] = result.withGenerated - } - index.duration = time.Since(startedAt) - }() +// keep holds what was read so far. +func (index *nameIndex) keep(results []unitIdentifiers) { + index.sets = make([]identifierSet, len(results)) + index.errs = make([]error, len(results)) + index.withGenerated = make([]bool, len(results)) + for position, result := range results { + index.sets[position] = result.set + index.errs[position] = result.err + index.withGenerated[position] = result.withGenerated + } } -// lookup waits for the index and returns the identifiers of one unit, or an error when it has none. +// lookup reads the sources when nothing has yet, waits for them and returns the identifiers of one +// unit, or an error when it has none. func (index *nameIndex) lookup(position int) (identifierSet, error) { if !index.started { return nil, errors.New("the names of the plan were never read") } + index.readSources() <-index.done if !index.indexed[position] { return nil, errors.New("the names of this unit were not read") @@ -245,20 +285,27 @@ func (index *nameIndex) lookup(position int) (identifierSet, error) { return index.sets[position], nil } -// wait returns once the background read is over, so nothing outlives the run that started it. +// wait returns once the background read of the sources is over, so nothing outlives the run that +// started it; at once when the sources were never asked for. func (index *nameIndex) wait() { - if index.started { + if index.started && index.sourcesRead.Load() { <-index.done } } -// report says what the read took; zero when nothing was read. +// report says what the read took; zero when nothing was read. It waits for the sources when they are +// being read. +// Why it waits itself rather than rely on wait: the run builds its outcome, and with it this report, +// before its deferred wait runs. func (index *nameIndex) report() NameIndexReport { if !index.started { return NameIndexReport{} } - <-index.done - report := NameIndexReport{Duration: index.duration} + sourcesRead := index.sourcesRead.Load() + if sourcesRead { + <-index.done + } + report := NameIndexReport{Duration: index.generatedDuration + index.sourcesDuration, SourcesRead: sourcesRead} for position, indexed := range index.indexed { if !indexed { continue @@ -274,8 +321,9 @@ func (index *nameIndex) report() NameIndexReport { return report } -// startNameIndex starts reading the identifiers of the units that reference another unit of the plan, -// when there is any. +// startNameIndex reads the generator output of the units that reference another unit of the plan, +// when there is any, and has the run read their sources once it first compiles a unit in full or has +// the worker check its changed files. func (run *schedulerRun) startNameIndex() { wanted := make([]bool, len(run.plan.Units)) any := false @@ -292,6 +340,9 @@ func (run *schedulerRun) startNameIndex() { generated[position] = filepath.Join(run.compiler.ProjectRoot, records.GeneratedDirectory(unit.Assembly.AssemblyName)) } run.names.start(run.compiler.ProjectRoot, run.plan.Units, generated, wanted) + // Why a compile or a check of changed files starts the read of the sources: either runs long + // enough to hide the read, while a run that only replays would wait for it. + run.compiler.beforeCompilerWork = run.names.readSources } // referenceEffect is what one reference's final state means for one unit that reads it: whether it diff --git a/cli/dispatcher/internal/compilecheck/name_index_fifo_test.go b/cli/dispatcher/internal/compilecheck/name_index_fifo_test.go index 293704ccb..aac8f5c7e 100644 --- a/cli/dispatcher/internal/compilecheck/name_index_fifo_test.go +++ b/cli/dispatcher/internal/compilecheck/name_index_fifo_test.go @@ -10,9 +10,9 @@ import ( "time" ) -// Verifies the generator output is read before start returns: with the background read held on a -// source until the generated directory is gone, as a compile that started meanwhile removes it, the -// names only the generator wrote are still in the index. +// Verifies the generator output is read before start returns: with the sources read only after the +// generated directory is gone, as a compile that started meanwhile removes it, and that read held on a +// source until the test releases it, the names only the generator wrote are still in the index. func TestNameIndexReadsGeneratedCodeBeforeStartReturns(t *testing.T) { root := t.TempDir() writeUnitSources(t, root, map[string]string{"Generated/Gen.g.cs": "partial class First { Foo f; }"}) @@ -32,6 +32,7 @@ func TestNameIndexReadsGeneratedCodeBeforeStartReturns(t *testing.T) { if err := os.RemoveAll(filepath.Join(root, "Generated")); err != nil { t.Fatalf("failed to remove the generated code: %v", err) } + index.readSources() releaseFIFO(t, source, "class First { }") set, err := index.lookup(0) @@ -41,6 +42,38 @@ func TestNameIndexReadsGeneratedCodeBeforeStartReturns(t *testing.T) { assertHasIdentifiers(t, set, []string{"First", "Foo"}, nil) } +// Verifies a run that never asks for the sources does not read them: with a source no writer ever +// opens, wait and report still return at once after start. +func TestNameIndexWaitReturnsAtOnceWhenTheSourcesWereNeverAsked(t *testing.T) { + root := t.TempDir() + source := filepath.Join(root, "Assets", "A.cs") + if err := os.MkdirAll(filepath.Dir(source), 0o755); err != nil { + t.Fatalf("failed to create the source directory: %v", err) + } + // Why a FIFO no one writes: opening it blocks forever, so any read of the sources holds wait. + if err := syscall.Mkfifo(source, 0o644); err != nil { + t.Fatalf("failed to create the source FIFO: %v", err) + } + unit := CompileUnit{Assembly: ResponseFile{AssemblyName: "Unit"}, Sources: []string{"Assets/A.cs"}} + index := nameIndex{} + index.start(root, []CompileUnit{unit}, []string{filepath.Join(root, "Generated")}, []bool{true}) + + reported := make(chan NameIndexReport, 1) + go func() { + index.wait() + reported <- index.report() + }() + + select { + case report := <-reported: + if report.SourcesRead || report.Units != 1 { + t.Errorf("report = %+v, want one unit whose sources were not read", report) + } + case <-time.After(5 * time.Second): + t.Fatal("wait or report held on sources nothing asked for") + } +} + // releaseFIFO writes content to the FIFO at path once its reader opens it, and fails the test when // no reader comes. func releaseFIFO(t *testing.T, path string, content string) { diff --git a/cli/dispatcher/internal/compilecheck/name_index_test.go b/cli/dispatcher/internal/compilecheck/name_index_test.go index bad746696..1ddfb846f 100644 --- a/cli/dispatcher/internal/compilecheck/name_index_test.go +++ b/cli/dispatcher/internal/compilecheck/name_index_test.go @@ -5,6 +5,7 @@ import ( "path/filepath" "strings" "testing" + "time" ) func identifiersOf(content string) identifierSet { @@ -155,13 +156,14 @@ func TestReadSourceIdentifiersRefusesAUnitItCannotRead(t *testing.T) { } } -// Verifies the background read is over once wait returns, and that lookup answers only for the -// units it was asked to read. +// Verifies the background read of the sources is over once wait returns after it was asked for, and +// that lookup answers only for the units it was asked to read. func TestNameIndexIsOverOnceWaitReturns(t *testing.T) { root := t.TempDir() unit := writeUnitSources(t, root, map[string]string{"Assets/A.cs": "class First { }"}) index := nameIndex{} index.start(root, []CompileUnit{unit, unit}, []string{filepath.Join(root, "Missing"), ""}, []bool{true, false}) + index.readSources() index.wait() @@ -180,3 +182,23 @@ func TestNameIndexIsOverOnceWaitReturns(t *testing.T) { t.Error("expected no identifiers from an index that never started") } } + +// Verifies the reported duration counts only the time spent reading, not the time the run spent +// before it asked for the sources. +// Why the bounds hold without flaking: the test waits 300 ms between start and readSources, so a +// duration measured from start is at least 300 ms, while reading one small file takes well under a +// millisecond; 150 ms leaves room on both sides for a slow machine. +func TestNameIndexReportCountsOnlyTheTimeSpentReading(t *testing.T) { + root := t.TempDir() + unit := writeUnitSources(t, root, map[string]string{"Assets/A.cs": "class First { }"}) + index := nameIndex{} + index.start(root, []CompileUnit{unit}, []string{filepath.Join(root, "Missing")}, []bool{true}) + time.Sleep(300 * time.Millisecond) + + index.readSources() + index.wait() + + if report := index.report(); !report.SourcesRead || report.Duration >= 150*time.Millisecond { + t.Errorf("report = %+v, want the sources read in well under 150 ms", report) + } +} diff --git a/cli/dispatcher/internal/compilecheck/result_cache.go b/cli/dispatcher/internal/compilecheck/result_cache.go index 7453b858e..2af126b32 100644 --- a/cli/dispatcher/internal/compilecheck/result_cache.go +++ b/cli/dispatcher/internal/compilecheck/result_cache.go @@ -53,6 +53,7 @@ func (c Compiler) reuseOrCompile( // Why nothing is recorded unless csc ran to completion: a compile that was cancelled or never // started says nothing about the inputs, and CompileUnit has already removed the manifest of the // compile this one replaces, so an interrupted run leaves no record at all rather than a stale one. + c.startCompilerWork() result, err := c.CompileUnit(ctx, plan, unit) result.FastPathFallbackReason = fallbackReason if err != nil || key == "" || result.RawOutput != "" { diff --git a/cli/dispatcher/internal/compilecheck/result_cache_compiler_work_test.go b/cli/dispatcher/internal/compilecheck/result_cache_compiler_work_test.go new file mode 100644 index 000000000..035a39067 --- /dev/null +++ b/cli/dispatcher/internal/compilecheck/result_cache_compiler_work_test.go @@ -0,0 +1,86 @@ +package compilecheck + +import ( + "context" + "os/exec" + "slices" + "testing" + "time" +) + +// compilerWorkMarks runs one unit through reuseOrCompile with a hook, a compiler and, when given, a +// worker check that all note when they are called, in the order they are. +func compilerWorkMarks( + t *testing.T, project *cachedSchedulerProject, fastPath *fastPathRunner, name string, +) (UnitResult, []string) { + t.Helper() + makeOutputDirectory(t, project.root, project.plan) + marks := []string{} + if fastPath != nil { + fastPath.Worker.(*fakeFastCheckWorker).onCheck = func() { marks = append(marks, "check") } + } + compile := newCachedSchedulerRecorder(name).runner() + compiler := Compiler{ + Paths: project.paths, + ProjectRoot: project.root, + Timeout: time.Minute, + Run: func(ctx context.Context, cmd *exec.Cmd) (string, string, int, error) { + marks = append(marks, "compile") + + return compile(ctx, cmd) + }, + FastPath: fastPath, + beforeCompilerWork: func() { marks = append(marks, "hook") }, + } + result, err := compiler.reuseOrCompile(context.Background(), project.plan, project.plan.Units[planIndexOf(t, project.plan, name)]) + if err != nil { + t.Fatalf("expected %s to produce a result, got error: %v", name, err) + } + + return result, marks +} + +// Verifies the compiler-work hook runs once, right before csc starts or the worker checks the changed +// files, and never for a unit whose result is replayed from its record or from the last check of the +// same edit. +func TestReuseOrCompileCallsTheCompilerWorkHookOnlyBeforeACompileOrACheck(t *testing.T) { + t.Run("full compile", func(t *testing.T) { + project := newCachedSchedulerProject(t, nil, "Alpha") + + _, marks := compilerWorkMarks(t, project, nil, "Alpha") + + if !slices.Equal(marks, []string{"hook", "compile"}) { + t.Errorf("marks = %v, want the hook once before the compile", marks) + } + }) + t.Run("replayed", func(t *testing.T) { + project := newCachedSchedulerProject(t, nil, "Alpha") + compilerWorkMarks(t, project, nil, "Alpha") + + result, marks := compilerWorkMarks(t, project, nil, "Alpha") + + if !result.Reused || len(marks) != 0 { + t.Errorf("reused = %v, marks = %v; want a replay with no hook", result.Reused, marks) + } + }) + t.Run("fast check", func(t *testing.T) { + project := newEditedFastPathProject(t) + + result, marks := compilerWorkMarks(t, project.cachedSchedulerProject, project.runner(false), "Alpha") + + if !result.FastChecked || result.FastCheckReused || !slices.Equal(marks, []string{"hook", "check"}) { + t.Errorf("fast checked = %v, reused = %v, marks = %v; want the hook once before the check", + result.FastChecked, result.FastCheckReused, marks) + } + }) + t.Run("fast check replayed", func(t *testing.T) { + project := newEditedFastPathProject(t) + compilerWorkMarks(t, project.cachedSchedulerProject, project.runner(false), "Alpha") + + result, marks := compilerWorkMarks(t, project.cachedSchedulerProject, project.runner(false), "Alpha") + + if !result.FastCheckReused || len(marks) != 0 { + t.Errorf("fast check reused = %v, marks = %v; want a replayed check with no hook", result.FastCheckReused, marks) + } + }) +} diff --git a/cli/dispatcher/internal/compilecheck/scheduler_names_test.go b/cli/dispatcher/internal/compilecheck/scheduler_names_test.go index c8689c85c..149cbca1e 100644 --- a/cli/dispatcher/internal/compilecheck/scheduler_names_test.go +++ b/cli/dispatcher/internal/compilecheck/scheduler_names_test.go @@ -279,3 +279,65 @@ func TestCompileUnitsCompilesAgainOnANameOnlyGeneratedCodeWritesWhenTheEarlyComp } assertChangedReferences(t, d2, []ChangedReference{{Assembly: "D1", Name: "Foo"}}) } + +// replayedNamesProject is newNamesProject after a first run that compiled A with a kept surface, so +// the next run replays A. B's sources are moved to a file that does not exist, so any read of them +// is counted as unreadable. +func replayedNamesProject(t *testing.T) (*cachedSchedulerProject, *schedulerRecorder) { + t.Helper() + project, recorder := newNamesProject(t, "class B { int Bar; }") + project.compileWithVerdicts(t, recorder, namedVerdicts{"A": {Kept: true, Reason: SurfaceSameAPI}}) + index := planIndexOf(t, project.plan, "B") + project.plan.Units[index].Sources = []string{"Assets/B/Missing.cs"} + + return project, recorder +} + +// Verifies a run that compiles nothing in full and whose every verdict is kept never reads the +// sources of the plan. +func TestCompileUnitsReadsNoSourcesWhenNothingCompilesAndEveryVerdictIsKept(t *testing.T) { + project, recorder := replayedNamesProject(t) + + outcome := project.compileWithVerdicts(t, recorder, namedVerdicts{"A": {Kept: true, Reason: SurfaceSameAPI}}) + + if !resultOf(t, outcome.Units, "A").Reused || outcome.Skipped != 1 { + t.Fatalf("A reused = %v, skipped = %d; want A replayed and B left out", + resultOf(t, outcome.Units, "A").Reused, outcome.Skipped) + } + if outcome.NameIndex.SourcesRead || outcome.NameIndex.Unreadable != 0 { + t.Errorf("name index = %+v, want the sources never read", outcome.NameIndex) + } +} + +// Verifies a replayed verdict that names its change reads the sources of the dependents it asks +// about, and a dependent writing none of the names is left out by names. +func TestCompileUnitsReadsTheSourcesWhenAReplayedVerdictNamesAChange(t *testing.T) { + project, recorder := replayedNamesProject(t) + project.plan.Units[planIndexOf(t, project.plan, "B")].Sources = []string{"Assets/B/B.cs"} + + outcome := project.compileWithVerdicts(t, recorder, namedVerdicts{"A": namedChangeOf("Foo")}) + + if !resultOf(t, outcome.Units, "A").Reused { + t.Fatal("expected A to be replayed") + } + want := []NameSkip{{Assembly: "B", ChangedReferences: []string{"A"}}} + if !reflect.DeepEqual(outcome.NameSkips, want) { + t.Errorf("name skips = %+v, want %+v", outcome.NameSkips, want) + } + if !outcome.NameIndex.SourcesRead || outcome.NameIndex.Unreadable != 0 { + t.Errorf("name index = %+v, want the sources read", outcome.NameIndex) + } +} + +// Verifies a run that compiles a unit in full reads the sources while it does, even when no verdict +// needs the names. +func TestCompileUnitsReadsTheSourcesOnceAUnitCompilesInFull(t *testing.T) { + project, recorder := newNamesProject(t, "class B { int Bar; }") + + outcome := project.compileWithVerdicts(t, recorder, namedVerdicts{"A": {Kept: true, Reason: SurfaceSameAPI}}) + + assertStrings(t, "results", compiledNames(outcome.Units), []string{"A"}) + if !outcome.NameIndex.SourcesRead { + t.Errorf("name index = %+v, want the sources read", outcome.NameIndex) + } +} diff --git a/cli/dispatcher/internal/dispatcher/compile_check_vibe_log.go b/cli/dispatcher/internal/dispatcher/compile_check_vibe_log.go index 74331aa1c..2af733511 100644 --- a/cli/dispatcher/internal/dispatcher/compile_check_vibe_log.go +++ b/cli/dispatcher/internal/dispatcher/compile_check_vibe_log.go @@ -204,6 +204,7 @@ func addCompileCheckVibeNameNarrowing(context map[string]any, result compilechec "units": result.NameIndex.Units, "with_generated": result.NameIndex.WithGenerated, "unreadable": result.NameIndex.Unreadable, + "sources_read": result.NameIndex.SourcesRead, } } } 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 1b12cffef..d1bf70488 100644 --- a/cli/dispatcher/internal/dispatcher/compile_check_vibe_log_test.go +++ b/cli/dispatcher/internal/dispatcher/compile_check_vibe_log_test.go @@ -263,7 +263,7 @@ func TestCompileCheckVibeLogRecordsNameNarrowing(t *testing.T) { }, Skipped: 1, NameSkips: []compilecheck.NameSkip{{Assembly: "Delta", ChangedReferences: []string{"Alpha"}}}, - NameIndex: compilecheck.NameIndexReport{Duration: 30 * time.Millisecond, Units: 3, WithGenerated: 1, Unreadable: 1}, + NameIndex: compilecheck.NameIndexReport{Duration: 30 * time.Millisecond, Units: 3, WithGenerated: 1, Unreadable: 1, SourcesRead: true}, } logRun := startCompileCheckVibeLog(projectRoot, compileCheckOptions{}) @@ -276,7 +276,26 @@ func TestCompileCheckVibeLogRecordsNameNarrowing(t *testing.T) { `"duration_ms":200,"succeeded":true}]`) assertVibeContextJSON(t, complete, "name_skips", `[{"assembly":"Delta","unaffected_by":["Alpha"]}]`) assertVibeContextJSON(t, complete, "name_index", - `{"duration_ms":30,"units":3,"unreadable":1,"with_generated":1}`) + `{"duration_ms":30,"sources_read":true,"units":3,"unreadable":1,"with_generated":1}`) +} + +// Verifies a run that read only the saved generator output of the units with references logs the +// name index and says it never read their sources. +func TestCompileCheckVibeLogRecordsANameIndexWhoseSourcesWereNotRead(t *testing.T) { + t.Setenv(vibelog.CLIVibeLogEnvName, "1") + projectRoot := t.TempDir() + result := compilecheck.Result{ + Units: []compilecheck.UnitResult{{Assembly: "Alpha", Succeeded: true, Reused: true}}, + Skipped: 2, + NameIndex: compilecheck.NameIndexReport{Duration: 2 * time.Millisecond, Units: 2}, + } + + logRun := startCompileCheckVibeLog(projectRoot, compileCheckOptions{}) + logRun.completed(buildCompileCheckResponse(result, projectRoot), result) + + complete := assertCompileCheckVibeRun(t, readCompileCheckVibeLog(t, projectRoot)) + assertVibeContextJSON(t, complete, "name_index", + `{"duration_ms":2,"sources_read":false,"units":2,"unreadable":0,"with_generated":0}`) } // Verifies a run that read no names and left nothing out by names logs neither. diff --git a/docs/compile-check.md b/docs/compile-check.md index 2b6afddb2..d97acce0f 100644 --- a/docs/compile-check.md +++ b/docs/compile-check.md @@ -72,6 +72,10 @@ references, scripting defines and analyzers. `compile-check` replays those respo interpolated string handler or collection builder type; every member of a type in `System`, `Microsoft.CodeAnalysis` or a namespace under them, which the compiler looks up by name for `init`, `^1` and the like; members that only moved; and a change naming more than 2000 names. A dependent whose sources cannot be read compiles too. + The saved generator output is read before any assembly compiles; the sources are read from the + moment the run first compiles an assembly or has the worker check its changed files, or first + needs the names for a verdict, whichever comes first; a run that only replays earlier results and + has no verdict that needs names never reads them. Its answer is kept in `.surface.json`, keyed by the content of both reference assemblies and the worker build, so the runs until Unity builds again do not compare the same pair twice. The comparison is always against Unity's own artifact, never against the diff --git a/docs/vibe-logs.md b/docs/vibe-logs.md index 70510648b..e97b7ca49 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; `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, `waited_for_record` says it waited for its references for a record that then did not apply, and `changed_by` lists the references whose changed surface counted for it (`reference`, and `name`, the first changed name it writes, empty when no name tells the change) - 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; `changed_name_count` and `changed_names`, the first 10 of the identifiers a dependent has to write to be affected by the change, and `unnamed`, why no name tells the change, only when it applies), `name_skips` (`assembly`, `unaffected_by`: the assemblies left out although a reference changed, because they write none of the names the change touches; only when there is any), and `name_index` (`duration_ms`, `units`, `with_generated`, `unreadable`: what reading the names of the assemblies with references in the plan took; only when any was read) | +| `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, `waited_for_record` says it waited for its references for a record that then did not apply, and `changed_by` lists the references whose changed surface counted for it (`reference`, and `name`, the first changed name it writes, empty when no name tells the change) - 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; `changed_name_count` and `changed_names`, the first 10 of the identifiers a dependent has to write to be affected by the change, and `unnamed`, why no name tells the change, only when it applies), `name_skips` (`assembly`, `unaffected_by`: the assemblies left out although a reference changed, because they write none of the names the change touches; only when there is any), and `name_index` (`duration_ms`, `units`, `with_generated`, `unreadable`, `sources_read`: what reading the names of the assemblies with references in the plan took, and whether the run read their sources - it does only once it compiles an assembly, has the worker check changed files, or a verdict needs the names; only when the plan has an assembly with references) | - 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