diff --git a/docs/internal/gotool.md b/docs/internal/gotool.md index dc7d575..c34f035 100644 --- a/docs/internal/gotool.md +++ b/docs/internal/gotool.md @@ -17,8 +17,14 @@ needed by the caller, such as compiler identification. After the child stops, the capture's backing bytes transfer to the caller without a second copy. A failed output command returns both those bytes and an error containing the diagnostic text. The capture remains in memory for the duration of the child; -an 8 MiB forwarded capture currently allocates about 8.39 MB per operation, -with the returned 8 MiB slice owned by its caller. Failed output also formats +the component benchmark compares one 8 MiB write with the same output in +32 KiB writes, forwarding to `io.Discard`. Smaller writes incur buffer-growth +allocations. The [workload-specific results](../roadmap/implementation.md#output-chunking-follow-up) +record total allocated bytes per operation, excluding subprocess overhead and +diagnostic strings. These totals count all allocations, including superseded +buffers. The returned slice retains the final buffer holding the complete output. +Peak live memory depends on buffer growth, garbage collection, and other command +work and is not measured by allocation totals. Failed output also formats diagnostics into the error, so the returned bytes and diagnostic string can coexist. Disk-backed diagnostics could reduce large failure peaks, but add file lifecycle and cleanup work and remain a follow-up option. diff --git a/docs/roadmap/implementation.md b/docs/roadmap/implementation.md index c564aa0..fd9aacb 100644 --- a/docs/roadmap/implementation.md +++ b/docs/roadmap/implementation.md @@ -150,7 +150,8 @@ before timing. The fixture server retains only digest and size metadata for uploads and streams known matching bytes directly from shared fixture content. Output measurements call the combined writer directly, with forwarding to -`io.Discard`, then capture its completed buffer. They include the current +`io.Discard`, then capture its completed buffer. Each baseline and final +comparison writes its complete input in one call. The baseline includes the completed-output copy. Runtime fallback measurements call `Version()` repeatedly against real build metadata; injected access measures the selection helper's injected-version branch. The benchmark process reports its own allocations, @@ -163,8 +164,8 @@ the fixture server. | Declarations plus local verification | 186.7–188.4 ms; 33,554,432 binary bytes per each of two passes; about 136.2 KB allocated. | 94.3–95.3 ms; one 33,554,432-byte verification pass; about 69.7 KB and 58–59 allocations. | | Facade delivery, fresh uploads | 429–447 ms; 32 MiB binary payload, two files plus manifest; 1.43–1.46 MB allocated. | 331.9–415.3 ms; same payload; 1.38–1.39 MB allocated. | | Facade delivery, matching retry | 309.1–310.0 ms; 32 MiB of local verification plus streamed remote comparisons; 1.21–1.22 MB allocated. | 210.7–217.5 ms; same local verification and streamed comparisons; 1.15 MB allocated. | -| Combined output, 4 KiB and `io.Discard` | 1.82–1.87 μs; 8,256 B and 3 allocations per operation. | 0.94–1.06 μs; 4,176 B and 2 allocations. | -| Combined output, 8 MiB and `io.Discard` | 2.02–2.36 ms; 16.78 MB and 3 allocations per operation, including the completed capture copy. | 1.73–2.22 ms; about 8.39 MB and 2 allocations. | +| Combined output, one 4 KiB write and `io.Discard` | 1.82–1.87 μs; 8,256 B and 3 allocations per operation. | 0.94–1.06 μs; 4,176 B and 2 allocations. | +| Combined output, one 8 MiB write and `io.Discard` | 2.02–2.36 ms; 16.78 MB and 3 allocations per operation, including the completed capture copy. | 1.73–2.22 ms; about 8.39 MB and 2 allocations. | | Injected version selection | 0.745–0.754 ns; 0 B and 0 allocations. | 0.754–0.758 ns; 0 B and 0 allocations. | | Repeated real metadata fallback | 1.438–1.474 μs; 1,184 B and 7 allocations per operation. | 4.59–4.65 ns after cache initialization; 0 B and 0 allocations. Separate initialization: 1.54–2.14 μs; 1,264 B and 9 allocations. | @@ -173,6 +174,31 @@ these fixtures. The output component benchmark does not include child startup; the real delivery benchmark does include HTTP request handling. These results describe measured workloads and do not establish runtime guarantees. +### Output Chunking Follow-Up + +The R3 follow-up extends `BenchmarkPerformanceCombinedOutput` with 32 KiB +writes. Three repetitions on Go 1.26.8, linux/amd64, and the Intel Core i5-7260U +used the completed writer at `7d92c47` with the extended benchmark: + +```sh +GOPROXY=off GOSUMDB=off GOTOOLCHAIN=local go test ./internal/gotool -run '^$' -bench '^BenchmarkPerformanceCombinedOutput$' -benchmem -count=3 -benchtime=1s +``` + +| Workload, forwarding to `io.Discard` | Elapsed time | Total allocated bytes/op | Allocations/op | Returned output length | +| --- | --- | --- | --- | --- | +| One 8 MiB write | 1.49–1.56 ms | 8,388,697–8,388,702 | 2 | 8,388,608 bytes | +| 32 KiB writes totaling 8 MiB | 2.56–2.93 ms | 16,744,532–16,744,541 | 10 | 8,388,608 bytes | + +Both workloads verify complete captured and forwarded bytes outside the timed +region. Measurements include capture and forwarding to `io.Discard`, excluding +subprocess costs and failure diagnostic strings. Total allocated bytes count +all allocations during an operation, including superseded buffers. The returned +slice retains the final backing buffer; its logical output length is 8 MiB in +both cases. Peak live memory was not measured and depends on buffer growth, +garbage collection, and other command work. These results describe the measured +workloads and establish no numerical runtime guarantee. Both paths transfer the +completed buffer without the former final copy. + ### Final Comparison Record The final benchmark run measured commit `42569b4`, before this Stage 11 record @@ -215,8 +241,8 @@ fresh uploads measured 331.9–415.3 ms and matching retries 210.7–217.5 ms. A retry still reads and verifies local assets and compares streamed remote bytes; those fixture and remote-comparison costs remain in the complete workflow. -Output capture allocations fell from 8,256 B to 4,176 B for 4 KiB, and from -about 16.78 MB to 8.39 MB for 8 MiB. The 8 MiB timing ranges overlap, while one +For single-write workloads, output capture allocations fell from 8,256 B to +4,176 B for 4 KiB, and from about 16.78 MB to 8.39 MB for 8 MiB. The 8 MiB timing ranges overlap, while one allocation and the completed-buffer copy are removed. The returned capture remains caller-owned in memory; a failed output command can also retain its diagnostic string. Warm runtime fallback access measured 4.59–4.65 ns and zero @@ -565,8 +591,8 @@ artifact compilation use `Run`; compiler identification uses `Output`. Preparation retains its network-capable environment and formats diagnostics from the transferred buffer. Go tool fixtures cover forwarded output, large failure output, cancellation, and writer failure. Go tool, validation, build, -facade, preparation, and CLI tests passed. The combined-output benchmark now -measures 1.0–1.1 µs and 4,176 B/2 allocations for 4 KiB, and 1.51–1.56 ms and +facade, preparation, and CLI tests passed. The single-write combined-output +benchmark now measures 1.0–1.1 µs and 4,176 B/2 allocations for 4 KiB, and 1.51–1.56 ms and 8,388,699–8,388,703 B/2 allocations for 8 MiB. The Stage 2 8 MiB result was 2.02–2.36 ms and about 16.78 MB/3 allocations, including its capture copy. The returned 8 MiB slice remains caller-owned in memory; failed Output also diff --git a/docs/roadmap/remediation.md b/docs/roadmap/remediation.md index eff98cf..3e9fea4 100644 --- a/docs/roadmap/remediation.md +++ b/docs/roadmap/remediation.md @@ -1,6 +1,6 @@ # Performance Implementation Remediation -**Status:** Remediation in progress; R1–R2 complete. +**Status:** Remediation in progress; R1–R3 complete. **Review baseline:** df064bd, reviewed on 2026-10-09 against the [performance target](performance.md) and @@ -126,6 +126,13 @@ design; these findings do not require disk-backed diagnostics or a memory cap. and confirm captured bytes and forwarding remain correct. Report allocation results as workload-specific measurements with no numerical runtime guarantee. +**Completion:** Complete. The benchmark now includes equal 8 MiB output in one +write and 32 KiB chunks, with untimed byte-for-byte capture and forwarding checks. +Three repetitions passed and measured about 8.39 MB/2 allocations and +16.74 MB/10 allocations respectively. Go-output documentation and implementation +results qualify the single-write figures and distinguish allocation totals, +retained output, and unmeasured peak memory. + ## R4: Reconcile Feature And Implementation Status **Priority:** Low. diff --git a/internal/gotool/performance_test.go b/internal/gotool/performance_test.go index d5af2b7..9df7e63 100644 --- a/internal/gotool/performance_test.go +++ b/internal/gotool/performance_test.go @@ -10,23 +10,40 @@ const performanceDiagnosticSize = 8 << 20 func BenchmarkPerformanceCombinedOutput(b *testing.B) { for _, testCase := range []struct { - name string - size int + name string + size int + chunkSize int }{ - {name: "modest", size: 4 << 10}, - {name: "diagnostic-8MiB", size: performanceDiagnosticSize}, + {name: "modest", size: 4 << 10, chunkSize: 4 << 10}, + {name: "diagnostic-8MiB", size: performanceDiagnosticSize, chunkSize: performanceDiagnosticSize}, + {name: "diagnostic-8MiB-32KiB-chunks", size: performanceDiagnosticSize, chunkSize: 32 << 10}, } { input := bytes.Repeat([]byte("go tool diagnostic output\n"), (testCase.size+25)/26) input = input[:testCase.size] b.Run(testCase.name+"/discard-forwarding", func(b *testing.B) { + // Verify capture and forwarding for this workload outside the measurement. + var forwarded bytes.Buffer + verification := &combinedWriter{output: &forwarded} + for offset := 0; offset < len(input); offset += testCase.chunkSize { + chunk := input[offset:min(offset+testCase.chunkSize, len(input))] + if written, err := verification.Write(chunk); err != nil || written != len(chunk) { + b.Fatalf("verify output write = %d, err %v; want %d bytes", written, err, len(chunk)) + } + } + if !bytes.Equal(verification.take(), input) || !bytes.Equal(forwarded.Bytes(), input) { + b.Fatal("captured and forwarded output must equal the complete input") + } b.ReportAllocs() b.SetBytes(int64(len(input))) b.ResetTimer() b.ReportMetric(float64(len(input)), "bytes/op") for i := 0; i < b.N; i++ { writer := &combinedWriter{output: io.Discard} - if written, err := writer.Write(input); err != nil || written != len(input) { - b.Fatalf("write captured output = %d, err %v; want %d bytes", written, err, len(input)) + for offset := 0; offset < len(input); offset += testCase.chunkSize { + chunk := input[offset:min(offset+testCase.chunkSize, len(input))] + if written, err := writer.Write(chunk); err != nil || written != len(chunk) { + b.Fatalf("write captured output = %d, err %v; want %d bytes", written, err, len(chunk)) + } } captured := writer.take() if len(captured) != len(input) {