diff --git a/cmd/comparecache/main.go b/cmd/comparecache/main.go index 2cf9162..7258cd8 100644 --- a/cmd/comparecache/main.go +++ b/cmd/comparecache/main.go @@ -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 { diff --git a/cmd/webicached/main.go b/cmd/webicached/main.go index d72e6bc..288fe04 100644 --- a/cmd/webicached/main.go +++ b/cmd/webicached/main.go @@ -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 }