feat(cache): add timing instrumentation to webicached and comparecache

Log classify/write/total per package in webicached, and
discover/compare/total in comparecache. Helps identify slow
packages as the dataset grows.
This commit is contained in:
AJ ONeal
2026-03-10 17:42:50 -06:00
parent 1412c7c374
commit 2b0b293728
2 changed files with 21 additions and 1 deletions

View File

@@ -23,6 +23,7 @@ import (
"slices"
"sort"
"strings"
"time"
"github.com/webinstall/webi-installers/internal/classify"
"github.com/webinstall/webi-installers/internal/lexver"
@@ -64,6 +65,8 @@ func main() {
flag.Parse()
filterPkgs := flag.Args()
totalStart := time.Now()
// Find the most recent month directory in each cache.
liveMonth := findLatestMonth(*liveDir)
goMonth := findLatestMonth(*goDir)
@@ -78,6 +81,7 @@ func main() {
}
// Discover all packages across both caches.
discoverStart := time.Now()
allPkgs := discoverPackages(livePath, goPath)
if len(filterPkgs) > 0 {
nameSet := make(map[string]bool, len(filterPkgs))
@@ -92,19 +96,24 @@ func main() {
}
allPkgs = filtered
}
log.Printf("discovered %d packages in %s", len(allPkgs), time.Since(discoverStart))
compareStart := time.Now()
var diffs []packageDiff
for _, pkg := range allPkgs {
d := compare(livePath, goPath, pkg, *latest, *windowed)
categorize(&d)
diffs = append(diffs, d)
}
log.Printf("compared %d packages in %s", len(diffs), time.Since(compareStart))
if *summary {
printSummary(diffs)
} else {
printDetails(diffs, *diffsOnly)
}
log.Printf("total: %s", time.Since(totalStart))
}
func findLatestMonth(dir string) string {

View File

@@ -139,6 +139,7 @@ func (wc *WebiCache) Run(filterPkgs []string) {
}
log.Printf("refreshing %d packages", len(packages))
runStart := time.Now()
for _, pkg := range packages {
if alias := pkg.conf.Extra["alias_of"]; alias != "" {
@@ -149,6 +150,8 @@ func (wc *WebiCache) Run(filterPkgs []string) {
log.Printf(" ERROR %s: %v", pkg.name, err)
}
}
log.Printf("refreshed %d packages in %s", len(packages), time.Since(runStart))
}
type pkgConf struct {
@@ -186,17 +189,21 @@ func discover(dir string) ([]pkgConf, error) {
// refreshPackage does the full pipeline for one package:
// fetch raw → classify → write to fsstore.
func (wc *WebiCache) refreshPackage(ctx context.Context, pkg pkgConf) error {
pkgStart := time.Now()
name := pkg.name
conf := pkg.conf
// Step 1: Fetch raw upstream data to rawcache (unless -no-fetch).
if !wc.NoFetch {
fetchStart := time.Now()
if err := wc.fetchRaw(ctx, pkg); err != nil {
return fmt.Errorf("fetch: %w", err)
}
log.Printf(" %s: fetch %s", name, time.Since(fetchStart))
}
// Step 2: Classify raw data into assets.
classifyStart := time.Now()
d, err := rawcache.Open(filepath.Join(wc.RawDir, name))
if err != nil {
return fmt.Errorf("rawcache open: %w", err)
@@ -212,8 +219,10 @@ func (wc *WebiCache) refreshPackage(ctx context.Context, pkg pkgConf) error {
// Step 3: Apply config transforms.
assets = applyConfig(assets, conf)
classifyDur := time.Since(classifyStart)
// Step 4: Write to fsstore.
writeStart := time.Now()
tx, err := wc.Store.BeginRefresh(ctx, name)
if err != nil {
return fmt.Errorf("begin refresh: %w", err)
@@ -225,8 +234,10 @@ func (wc *WebiCache) refreshPackage(ctx context.Context, pkg pkgConf) error {
if err := tx.Commit(ctx); err != nil {
return fmt.Errorf("commit: %w", err)
}
writeDur := time.Since(writeStart)
log.Printf(" %s: %d assets", name, len(assets))
log.Printf(" %s: %d assets (classify %s, write %s, total %s)",
name, len(assets), classifyDur, writeDur, time.Since(pkgStart))
return nil
}