diff --git a/docs/roadmap/startup-benchmark.md b/docs/roadmap/startup-benchmark.md index 232cf48..f8dc7fc 100644 --- a/docs/roadmap/startup-benchmark.md +++ b/docs/roadmap/startup-benchmark.md @@ -1,12 +1,12 @@ -# Startup construction baseline and first optimization proposal +# Startup construction measurements and focused experiments -Status: Stages 1–3 complete; the first Stage 4 experiment is retained. Further -optimization and complete consumer-workload verification remain outstanding. +Status: Stages 1–3 complete; Stage 4 is in progress with two retained experiments. +Complete consumer-workload verification remains outstanding. Measured on 2026-10-09 under the [startup roadmap](startup.md). The [consumer request](promptkit-performance-request.md) owns the submitted workload and measurements. This document records the reproduced baselines, maintained -benchmark, profiles, and proposed first change. It introduces no performance +benchmark, profiles, and focused experiment results. It introduces no performance contract or release gate. ## Environment and revisions @@ -463,16 +463,17 @@ prominent. Pointer formatting still accounts for nearly 19% of sampled CPU, including `strings.Count` work, so further formatting changes would need to justify their own extra complexity. -The recommended next experiment is to investigate combining the two walks of -the final tree in `finalizeMetadataPaths`: it first calls `effectivePathIndex` -and then walks the same final tree again for historical paths. One traversal -could populate both indexes and format each final path once, while retaining +At completion of the first experiment, the recommended next experiment was to +investigate combining the two walks of the final tree in `finalizeMetadataPaths`: +it first called `effectivePathIndex` and then walked the same final tree again +for historical paths. One traversal could populate both indexes and format each +final path once, while retaining the separate records, contextual segment kinds, ownership copies, and all walks of earlier/application/inheritance trees. This is a concrete redundancy to measure before considering broader path representation or ownership changes. -Its expected benefit is not established yet. A generic `Keys` constructor -rewrite is smaller, but only accounted for 0.78% of sampled allocated bytes in -the after profile, so it is a lower-priority candidate. +Its benefit had not yet been established; the experiment below now records it. +A generic `Keys` constructor rewrite is smaller, but only accounted for 0.78% of +sampled allocated bytes in the after profile, so it is a lower-priority candidate. The path/metadata/provenance/query/explanation/secret tests passed with the candidate. The existing path test now additionally checks decimal formatting @@ -482,3 +483,249 @@ documentation links and facade boundaries), vet, and builds. This experiment does not complete Stage 5: PromptKit's file-backed, shared-base, and layered fixtures plus its applicable configuration tests still belong to the final consumer verification. No consumer upgrade or release is published. + +## Focused experiment: combine final metadata traversal + +Status: Complete; retain the change. Measured on 2026-10-09. This is the second +Stage 4 experiment, not completion of the final consumer verification. + +### Change and ownership boundaries + +`finalizeMetadataPaths` formerly built the effective index with +`effectivePathIndex(final)`, then walked the same final tree again to seed the +historical index. It now allocates the two maps separately and walks the final +tree once. Each visited path is formatted once for insertion into those maps. +The effective index stores its own `path.clone()`; the existing historical +insertion/deduplication logic stores a separate clone. The maps may share an +immutable pointer string, not mutable path-segment storage. + +The historical helper accepts the already-formatted pointer so the final +callback can reuse it. Earlier trees, override applications, and inheritance +controls/transfers retain their existing walks, order, contextual path kinds, +and deduplication. `effectivePathIndex` remains unchanged for resolution input. +Nil final input still skips traversal while leaving both maps initialized. +There is no public API, configuration-semantic, dependency, cache, pooling, +release-gate, or result-lifetime change. + +### Revisions and reproduction + +- Before: `673faea097fb9a178b5743e71cbdcbecd215568f`, including the retained + `Path.String` optimization. These are fresh measurements, not comparisons + that bundle the two optimizations together. +- After: the candidate accompanying this section. Its only production change is + in `internal/engine/metadata.go`, Git blob + `e22804d659efb203a3829382a21e4e8d059b6c5f`; the accompanying tests and this + report are not part of timed construction. +- PromptKit: `eb830bb61346672f0f6c5bce6119b76ccc6d61ac`, unchanged for both + candidates. Its independent fixture retains the timing boundaries described + in Stage 1, including adapter processing after ConfigKit returns. +- Toolchain, hardware, runtime settings, fixture sizes, and setup boundaries + match the environment and maintained benchmark above. All measurements ran + sequentially; profiles and correctness checks did not overlap timed runs. + Shared-host scheduling and CPU frequency were not controlled. +- Raw benchmark logs, profiles, and binaries are outside both repositories at + `/tmp/configkit-final-walk.uDFTyU`. A disposable ConfigKit clone holds the + before revision; a disposable PromptKit clone alternately uses a module + replacement pointing to that clone or the working candidate. No original + consumer files or committed dependencies changed. + +Run from each ConfigKit candidate with matching settings: + +```sh +GOTOOLCHAIN=local GOWORK=off GOPROXY=off GOMAXPROCS=4 \ + go test -mod=readonly -run '^$' -bench '^BenchmarkStartupConstruction$' \ + -benchmem -benchtime=500ms -count=5 + +GOTOOLCHAIN=local GOWORK=off GOPROXY=off GOMAXPROCS=4 \ + go test -mod=readonly ./internal/engine -run '^$' \ + -bench '^(BenchmarkComposeWideMappings|BenchmarkUnderlayBroadCatalog|BenchmarkUnderlayRenderedHistory|BenchmarkInheritanceInspectedLoad)$' \ + -benchmem -benchtime=200ms -count=3 +``` + +For each candidate, rewire only the disposable PromptKit copy with the +`go mod edit -replace` command in Stage 1, then run its same independent +benchmark with `-benchtime=500ms -count=5`. Initial batches ran before, then +after. Longer repeats reversed that order: after, then before. Construction +and consumer repeats used `-benchtime=1s -count=5`; complementary repeats +used `-benchtime=500ms -count=5`. + +### Fresh construction results + +Every cell is the per-metric median of five observations. No outliers were +removed. These timing differences are descriptive, not statistical evidence +of a speedup or regression. + +| Workload | Before ms | After ms | Before B | After B | Before allocations | After allocations | +| --- | ---: | ---: | ---: | ---: | ---: | ---: | +| Local / 32 pairs | 17.363 | 17.175 | 11,036,876 | 10,887,031 | 80,465 | 78,605 | +| Local / 128 pairs | 61.612 | 62.541 | 43,513,114 | 42,912,759 | 319,130 | 311,702 | +| Local / 512 pairs | 251.336 | 256.408 | 173,804,200 | 170,796,144 | 1,273,712 | 1,244,003 | +| PromptKit / independent | 66.861 | 87.909 | 46,174,781 | 45,525,968 | 338,168 | 330,483 | + +Local allocation counts fell by 2.31%, 2.33%, and 2.33%, respectively; allocated +bytes fell by 1.36%, 1.38%, and 1.73%. PromptKit showed 2.27% fewer allocations +and 1.41% fewer allocated bytes. Its total still includes consumer adapter +work, rather than measuring only ConfigKit. + +Initial timing ranges (ms): + +| Workload | Before range | After range | +| --- | ---: | ---: | +| Local / 32 pairs | 16.547–19.567 | 16.740–20.823 | +| Local / 128 pairs | 58.494–69.982 | 58.401–68.902 | +| Local / 512 pairs | 243.146–279.740 | 249.116–439.932 | +| PromptKit / independent | 64.033–126.770 | 84.062–125.970 | + +The initial PromptKit median was 31% higher after the change; the larger local +medians were also slightly higher. Longer reverse-order repeats gave: + +| Workload | Before ms | After ms | Before range | After range | +| --- | ---: | ---: | ---: | ---: | +| Local / 32 pairs | 18.397 | 17.487 | 18.323–19.124 | 17.322–18.628 | +| Local / 128 pairs | 62.551 | 61.602 | 58.959–66.066 | 58.348–63.903 | +| Local / 512 pairs | 258.394 | 251.583 | 239.896–263.039 | 247.995–304.867 | +| PromptKit / independent | 68.283 | 68.134 | 63.908–71.703 | 64.020–73.127 | + +The consumer's initial slowdown did not recur. All four repeat ranges overlap. +Allocation reductions recur: local count medians remain 2.31–2.33% lower and +byte medians 1.36–1.43% lower; PromptKit remains 2.27% and 1.38% lower, +respectively. At 128 pairs, the longer run changed from 43,510,872 B and +319,132 allocations to 42,888,256 B and 311,702 allocations. + +### Complementary workloads and timing investigation + +Initial complementary results are per-metric medians of three observations: + +| Benchmark / size | Before ms | After ms | Before B | After B | Before allocations | After allocations | +| --- | ---: | ---: | ---: | ---: | ---: | ---: | +| ComposeWideMappings / 128 | 0.824 | 1.166 | 797,564 | 797,564 | 5,962 | 5,962 | +| ComposeWideMappings / 256 | 1.676 | 1.755 | 1,595,291 | 1,595,293 | 11,860 | 11,860 | +| ComposeWideMappings / 512 | 4.235 | 4.293 | 3,403,281 | 3,403,290 | 23,659 | 23,659 | +| InheritanceInspectedLoad / 16 | 1.127 | 1.211 | 835,681 | 832,237 | 8,060 | 7,990 | +| InheritanceInspectedLoad / 32 | 2.035 | 1.960 | 1,466,907 | 1,460,263 | 14,145 | 14,011 | +| InheritanceInspectedLoad / 64 | 4.093 | 4.150 | 2,752,251 | 2,739,211 | 26,360 | 26,098 | +| UnderlayBroadCatalog / 128 | 1.618 | 1.613 | 1,229,411 | 1,218,907 | 12,628 | 12,370 | +| UnderlayBroadCatalog / 256 | 3.296 | 3.479 | 2,459,362 | 2,437,599 | 24,821 | 24,307 | +| UnderlayBroadCatalog / 512 | 6.703 | 8.523 | 4,975,266 | 4,930,978 | 49,177 | 48,151 | +| UnderlayRenderedHistory / 32 | 0.290 | 0.659 | 503,458 | 503,461 | 3,221 | 3,221 | +| UnderlayRenderedHistory / 64 | 2.085 | 1.204 | 1,003,942 | 1,003,947 | 6,392 | 6,392 | +| UnderlayRenderedHistory / 128 | 3.331 | 2.723 | 2,027,690 | 2,027,695 | 12,732 | 12,732 | + +Inheritance loading and broad-underlay loading allocate less in every case. +Pure composition does not run metadata finalization and its allocation counts +are unchanged. History rendering also has unchanged allocation counts, as +expected: loading is outside its timed section. Small byte differences in +those unaffected measurements do not establish an allocation improvement. + +The longer reverse-order complementary batches produced these medians and +ranges (ms), retaining all five observations: + +| Benchmark / size | Before ms | After ms | Before range | After range | +| --- | ---: | ---: | ---: | ---: | +| ComposeWideMappings / 128 | 0.915 | 0.858 | 0.883–1.512 | 0.839–0.922 | +| ComposeWideMappings / 256 | 1.762 | 1.733 | 1.732–1.857 | 1.613–1.962 | +| ComposeWideMappings / 512 | 4.853 | 4.443 | 4.531–5.321 | 4.197–6.346 | +| InheritanceInspectedLoad / 16 | 1.200 | 1.822 | 1.133–1.494 | 1.652–1.951 | +| InheritanceInspectedLoad / 32 | 2.141 | 3.177 | 2.130–2.208 | 3.055–3.634 | +| InheritanceInspectedLoad / 64 | 4.169 | 5.066 | 4.054–4.460 | 3.883–8.171 | +| UnderlayBroadCatalog / 128 | 1.736 | 1.852 | 1.595–1.831 | 1.718–2.510 | +| UnderlayBroadCatalog / 256 | 3.712 | 3.743 | 3.413–3.843 | 3.378–7.093 | +| UnderlayBroadCatalog / 512 | 7.479 | 12.938 | 7.140–8.168 | 11.075–13.368 | +| UnderlayRenderedHistory / 32 | 0.326 | 0.563 | 0.311–1.048 | 0.530–0.583 | +| UnderlayRenderedHistory / 64 | 0.719 | 1.083 | 0.651–3.182 | 0.931–1.145 | +| UnderlayRenderedHistory / 128 | 1.435 | 2.567 | 1.361–5.152 | 2.289–2.887 | + +Allocation-count medians in these repeats match the initial complementary +table. Timing remains mixed: several loading and rendering cases were much +slower in the after batch, while the unchanged pure-composition cases were +faster. To investigate the substantial apparent regressions, two additional +alternating rounds ran after/before, then after/before, with +`-benchtime=1s -count=3` and this benchmark selector: + +```sh +GOTOOLCHAIN=local GOWORK=off GOPROXY=off GOMAXPROCS=4 \ + go test -mod=readonly ./internal/engine -run '^$' \ + -bench '^(BenchmarkInheritanceInspectedLoad|BenchmarkUnderlayBroadCatalog|BenchmarkUnderlayRenderedHistory)$/^(16|32|512)$' \ + -benchmem -benchtime=1s -count=3 +``` + +| Round / benchmark / size | Before ms | After ms | Before range | After range | +| --- | ---: | ---: | ---: | ---: | +| 1 / InheritanceInspectedLoad / 16 | 1.126 | 1.166 | 1.116–1.151 | 1.139–1.187 | +| 1 / InheritanceInspectedLoad / 32 | 2.064 | 2.070 | 2.023–2.133 | 2.053–2.148 | +| 1 / UnderlayBroadCatalog / 512 | 6.949 | 6.822 | 6.904–7.461 | 6.785–7.204 | +| 1 / UnderlayRenderedHistory / 32 | 0.312 | 0.311 | 0.304–0.317 | 0.306–0.314 | +| 2 / InheritanceInspectedLoad / 16 | 1.196 | 1.174 | 1.135–1.270 | 1.125–1.218 | +| 2 / InheritanceInspectedLoad / 32 | 2.196 | 2.047 | 2.108–2.224 | 2.023–2.084 | +| 2 / UnderlayBroadCatalog / 512 | 7.514 | 7.286 | 7.291–7.645 | 6.767–7.319 | +| 2 / UnderlayRenderedHistory / 32 | 0.332 | 0.324 | 0.327–0.345 | 0.323–0.342 | + +The large regressions did not recur. Inheritance / 16 was about 4% slower in +the first alternating round and about 2% faster in the second; the ranges +overlap in both. The other targeted cases were similar or faster after the +change, with the same allocation counts as the initial table. This supports +host/run variation as the explanation for the large batch differences, but +does not establish that every operation is faster or exclude small timing +costs. The allocation reduction is the more repeatable result. + +### Profile attribution and retention decision + +Separate profiles used the local 128-pair fixture and +`-benchtime=2s`, with explicit output paths outside the repositories: + +```sh +GOTOOLCHAIN=local GOWORK=off GOPROXY=off GOMAXPROCS=4 \ + go test -mod=readonly -run '^$' -bench '^BenchmarkStartupConstruction/128$' \ + -benchmem -benchtime=2s -cpuprofile=/absolute/temp/cpu.pprof \ + -memprofile=/absolute/temp/mem.pprof -o /absolute/temp/configkit.test + +go tool pprof -list='engine.finalizeMetadataPaths' -alloc_space /absolute/temp/mem.pprof +go tool pprof -list='engine.finalizeMetadataPaths$' /absolute/temp/cpu.pprof +go tool pprof -top -nodecount=12 -alloc_space /absolute/temp/mem.pprof +``` + +The before profiled run completed 34 timed operations at 66.339 ms, +43,468,634 B, and 319,128 allocations per operation. After completed 37 at +62.460 ms, 42,872,869 B, and 311,703 allocations. These are separate from +ordinary timing comparisons; raw profile totals include different operation +counts and must not be compared as per-load costs. + +The finalizer's cumulative share of sampled allocation bytes changed from +12.04% to 9.75%. Its line profile now attributes final-index construction to +one walk, rather than the former two call sites. The remaining +`effectivePathIndex.func1` belongs to resolution input; its flat allocation +share changed from 3.67% to 2.31%. `clonePathSegments` remains the largest flat +site (34.64% before, 33.49% after); required ownership copies remain in place. +The finalizer's sampled cumulative CPU share was 8.01% before and 7.87% after, +while `Path.String` changed from 17.21% to 19.10%. These short profiles support +allocation attribution, not a general CPU-speedup claim. + +Retain the change. The longer 128-pair run removes approximately 7,430 +allocations and 623 KB per construction; the reduction is reproduced at all +local sizes and in the consumer. Combining the initial walks adds little +implementation complexity while retaining both indexes, independent path +storage, and historical shapes. The possible small timing costs and noisy +batch results are recorded, not turned into a performance promise. Retained +heap was not measured separately; no persistent cache or new result lifetime +is introduced. + +### Validation and remaining work + +The two new metadata tests passed against the original production code before +the refactor and then against the candidate. They verify independently owned +effective/historical segments in both mutation directions, and retention of +both numeric-key and sequence-index historical shapes despite repeated tree +contributions. Existing tests continue to own removed descendants, root and +escaped paths, detached queries, resolution snapshots, independent loads, +inheritance, safe explanation, and sensitivity. + +The focused engine tests for paths, metadata, provenance, queries, resolution, +inheritance, explanation, sensitivity, secrets, and independence passed. +`go test -race ./internal/engine` passed. `./scripts/check.sh` passed +formatting, whitespace, the offline default suite, vet, and builds. +Documentation changes passed the local-link and whitespace checks. + +This focused experiment is complete. Stage 4 has two retained changes, while +Stage 5's complete consumer verification remains outstanding: PromptKit's +file-backed, shared-base, and layered fixtures and its applicable configuration +tests. No consumer dependency upgrade or release is published. diff --git a/docs/roadmap/startup.md b/docs/roadmap/startup.md index 17d0692..8905f34 100644 --- a/docs/roadmap/startup.md +++ b/docs/roadmap/startup.md @@ -1,6 +1,6 @@ # Startup Loading Performance Roadmap -Status: Stages 1–3 complete; Stage 4 is in progress with the first optimization +Status: Stages 1–3 complete; Stage 4 is in progress with two optimizations retained. Findings and reproduction commands are in [startup-benchmark.md](startup-benchmark.md). @@ -122,10 +122,11 @@ finding and recommend whether further investigation is justified. ### 4. Implement and measure focused changes -Status: In progress. `Path.String` buffer sizing is retained after fresh -construction, consumer, inspection, and profile comparisons. See the -[focused experiment](startup-benchmark.md#focused-experiment-pre-size-pathstring). -The next candidate is duplicate final-tree traversal during metadata finalization. +Status: In progress. `Path.String` buffer sizing and combined final metadata +traversal are retained after fresh construction, consumer, inspection, and +profile comparisons. See the [path-formatting experiment](startup-benchmark.md#focused-experiment-pre-size-pathstring) +and [metadata-traversal experiment](startup-benchmark.md#focused-experiment-combine-final-metadata-traversal). +Complete consumer-workload verification remains outstanding. 1. Implement the selected internal change while preserving the supported API and established behavior. Audit any reduced copying or reused data for diff --git a/internal/engine/metadata.go b/internal/engine/metadata.go index 4a10809..e22804d 100644 --- a/internal/engine/metadata.go +++ b/internal/engine/metadata.go @@ -109,10 +109,9 @@ func (m Metadata) hasHistoricalPath(path Path) bool { } func finalizeMetadataPaths(m *Metadata, final *document.Node, applications []historyApplication, earlier ...*document.Node) { - m.effectivePaths = effectivePathIndex(final) + m.effectivePaths = make(map[string]Path) m.historicalPaths = make(map[string][]Path) - add := func(path Path, _ *document.Node) { - pointer := path.String() + addHistorical := func(path Path, pointer string) { for _, prior := range m.historicalPaths[pointer] { if matchesPathShape(path, prior) { return @@ -120,7 +119,14 @@ func finalizeMetadataPaths(m *Metadata, final *document.Node, applications []his } m.historicalPaths[pointer] = append(m.historicalPaths[pointer], path.clone()) } - walkDocument(final, Path{}, add) + walkDocument(final, Path{}, func(path Path, _ *document.Node) { + pointer := path.String() + m.effectivePaths[pointer] = path.clone() + addHistorical(path, pointer) + }) + add := func(path Path, _ *document.Node) { + addHistorical(path, path.String()) + } for _, tree := range earlier { walkDocument(tree, Path{}, add) } diff --git a/internal/engine/metadata_test.go b/internal/engine/metadata_test.go index 88fa605..628d352 100644 --- a/internal/engine/metadata_test.go +++ b/internal/engine/metadata_test.go @@ -47,6 +47,60 @@ func TestMetadataHistoricalPaths(t *testing.T) { } } +func TestMetadataPathIndexesOwnIndependentSegments(t *testing.T) { + t.Parallel() + + final := parseDocumentForDecode(t, "service: {workers: [1]}\n") + var metadata Metadata + finalizeMetadataPaths(&metadata, final, nil) + pointer := "/service/workers/0" + effective := metadata.effectivePaths[pointer] + historical := metadata.historicalPaths[pointer] + if effective.String() != pointer || len(historical) != 1 || historical[0].String() != pointer { + t.Fatalf("path indexes = %#v, %#v", effective, historical) + } + + effective.segments[0].key = "effective" + if historical[0].String() != pointer { + t.Fatal("effective path mutation changed historical path") + } + historical[0].segments[2].index = 1 + if effective.String() != "/effective/workers/0" { + t.Fatal("historical path mutation changed effective path") + } +} + +func TestMetadataPathIndexesRetainDistinctHistoricalShapes(t *testing.T) { + t.Parallel() + + final := parseDocumentForDecode(t, "shape: [replacement]\n") + earlier := parseDocumentForDecode(t, "shape: {'0': base}\n") + var metadata Metadata + // Repeated trees must not add duplicate shapes to the historical index. + finalizeMetadataPaths(&metadata, final, nil, earlier, earlier, final) + keyPath := Keys("shape", "0") + indexPath := Keys("shape").Index(0) + pointer := indexPath.String() + if !reflect.DeepEqual(metadata.effectivePaths[pointer], indexPath) { + t.Fatal("effective index does not reflect the final sequence") + } + historical := metadata.historicalPaths[pointer] + if len(historical) != 2 { + t.Fatalf("historical shapes = %#v, want one key and one index", historical) + } + for _, want := range []Path{keyPath, indexPath} { + found := false + for _, path := range historical { + if reflect.DeepEqual(path, want) { + found = true + } + } + if !found || !metadata.hasHistoricalPath(want) { + t.Fatalf("historical index lost shape %#v", want) + } + } +} + func TestHistoricalPathsExposeHiddenBaseOwnershipWithoutResolvingBaseSecrets(t *testing.T) { t.Setenv("CONFIGKIT_HISTORY_UNUSED_PROD_KEY", "") t.Setenv("CONFIGKIT_HISTORY_TEST_KEY", "synthetic-test-key")