Conversation
scanLog used compiled regexes (FUNC/CALLED) against a fully-allocated per-line string via scanner.Text(). Regexp.FindStringSubmatch on every line is the single biggest cost in report generation as log size grows (issue #123). Replace with scanner.Bytes() + bytes.HasPrefix + bytes.IndexAny, converting to string only for the two substrings that actually become map keys. Benchmark (20k-line functions.log): scanLog 54.3ms -> 9.8ms (5.5x), analyzeLogs (50 images x 500 funcs x 4 called-log files) 114.7ms -> 45.9ms (2.5x). Also adds report_bench_test.go with synthetic-corpus benchmarks for scanLog/analyzeLogs/generateHTMLReport/generateXUnitReport to track further optimizations in this series.
generateHTMLReport and generateAggregateHTMLReport re-parsed their (compile-time-constant) template strings on every call. Parse once into package-level *template.Template vars instead. Also fixed the HTML/XUnit benchmarks: they used 1 image with a huge function count, which doesn't exercise the per-call template-reparse cost at all (that cost scales with number of images, not functions per image, since generateHTMLReport/generateXUnitReport are called once per image by emitReport). Switched to many images with modest per-image function counts. Benchmark (200 images x 50 functions): generateHTMLReport 150.8ms -> 121.1ms (-20%), allocs 244279 -> 194230. generateXUnitReport unaffected (doesn't use html/template) - that's bottleneck D's job.
generateXUnitReport built a throwaway single-entry map just to call summarizeCoverage() and recover totals it already had locally (totalCount/calledCount/pct are mathematically identical to summary.TotalFunctions/TotalCalled/AverageCoverage when there's exactly one image). Use the local values directly. Benchmark impact is small in practice (allocs 31436 -> 30446, ~1k fewer per 200-image run; no measurable time change) - this was more a correctness/clarity cleanup than a real bottleneck, unlike A/B.
generateXUnitReport, generateHTMLReport, and generateAggregateHTMLReport all wrote to a raw *os.File, so html/template.Execute and xml.Encoder's many small Write() calls each became a syscall. Added a writeBuffered helper (bufio.Writer, flushed before close) used by all three. Benchmark (200 images x 50 functions): generateHTMLReport 121.1ms -> 67.6ms (-44%). generateXUnitReport ~unchanged (its write volume per call is small enough that syscall count wasn't the bottleneck there).
analyzeLogs: scan log files concurrently (golang.org/x/sync/errgroup, bounded to GOMAXPROCS). Each file scans into its own local coverage map (scanLog mutates a map in place, and Go maps reject concurrent writes even to disjoint keys) which are merged sequentially once every scan completes - avoids locking the shared map entirely. emitReport: generate each image's HTML/XML report concurrently. Each writes to a distinct output file, so this is embarrassingly parallel; per-image errors are still logged individually rather than aborting the batch, matching prior behavior. Library enumeration (EnumerateFunctions) was also parallelized in an earlier draft of this commit but reverted per review - it's install/ trace-time work, not report generation, and out of scope for what issue #123 and this benchmark series are measuring. Benchmark (200 images x 50 functions, 20 iterations): analyzeLogs (50 images x 500 funcs x 4 called-log files): ~46ms -> ~37ms emitReport("html", ...): 78.5ms -> 9.3ms (8.4x) emitReport("xml", ...): 12.2ms -> 3.7ms (3.3x) Verified race-clean with `go test -race ./...` and the benchmarks themselves under -race.
cilium/ebpf and golang.org/x/sync were already at their latest available versions (v0.22.0 both) after rebasing onto main. demangle had a newer pseudo-version available; bumped and reverified full test suite under -race.
go run tests/gen_report_bench_corpus.go <outdir> <numImages> <funcsPerImage> <calledFilesPerImage> writes a deterministic _functions.log/_called.log corpus, simulating issue #123's scenario (many binaries/libraries traced) without needing to actually install and run hundreds of real binaries. Same args always produce byte-identical output, so before/after report-generation timing runs are directly comparable.
|
Codecov Report❌ Patch coverage is
Additional details and impacted files@@ Coverage Diff @@
## main #127 +/- ##
==========================================
+ Coverage 42.62% 43.73% +1.10%
==========================================
Files 11 11
Lines 1499 1525 +26
==========================================
+ Hits 639 667 +28
+ Misses 763 762 -1
+ Partials 97 96 -1 ☔ View full report in Codecov by Harness. 🚀 New features to boost your workflow:
|
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
2 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Summary
Implements the optimization plan from
plan.md(issue #123: report generation gets slow as the number of traced binaries/libraries grows, observed on os-autoinst SUT VMs). All five identified bottlenecks addressed incmd/report.go/cmd/funkoverage.go:scanLog: replaced regexp matching (FUNC/CALLEDline parsing) with byte-prefix +bytes.IndexAnyscanning.detailedHTMLTemplateStr/aggregateHTMLTemplate) parsed once at package init instead of on everygenerateHTMLReport/generateAggregateHTMLReportcall.generateXUnitReportno longer builds a throwaway single-entry map just to recompute totals it already has locally.writeBufferedhelper), flushed before close.analyzeLogsscans log files concurrently (golang.org/x/sync/errgroup, bounded toGOMAXPROCS), merging each file's local coverage map sequentially afterward (avoids any shared-map locking).emitReportgenerates each image's HTML/XML concurrently, since each writes to a distinct file.EnumerateFunctions) was parallelized in an earlier draft and reverted — that's install/trace-time work, not report generation, out of scope here.Also bumped
github.com/ianlancetaylor/demangleto latest (cilium/ebpfandgolang.org/x/syncwere already at latest after rebasing ontomain).Local benchmarks
go test ./cmd/ -bench=. -benchmem(synthetic data, seecmd/report_bench_test.go):scanLog(20k-line log)analyzeLogs(50 images × 500 funcs × 4 called-log files)emitReport("html", ...)(200 images × 50 funcs)emitReport("xml", ...)(200 images × 50 funcs)Large-scale before/after benchmark
A synthetic corpus of 2000 images × 300 functions (600,000 total functions, 360,000 called, 94MB across 8000 log files — generated deterministically via
go run tests/gen_report_bench_corpus.go), simulating "many binaries/libraries traced" per the issue.funkoverage report <corpus> <outdir> --formats html,xml,txt, 3 runs each:main)issue-123)~3.6x faster on realistic scale, with zero regression:
Total Functions: 600000,Total Called: 360000,Average Coverage: 60.00%identical before/after; the fulltxtreport is byte-for-byte identical, and per-image HTML/XML content is identical excluding timestamps. File counts match exactly (2000 XML, 2001 HTML includingaggregate.html).Test plan
go build ./...,go vet ./...,go test ./...pass (56 tests)go test -race ./...clean, including the new concurrent code paths and their benchmarkscmd/report_bench_test.go) and compared before/after each change