diff --git a/internal/tasks/aggregationBenchmark.go b/internal/tasks/aggregationBenchmark.go index 04c3695..69de7c7 100644 --- a/internal/tasks/aggregationBenchmark.go +++ b/internal/tasks/aggregationBenchmark.go @@ -44,29 +44,46 @@ func (c *CronTask) RunCanonicalAggregationBenchmark(ctx context.Context, runs in } report := AggregationBenchmarkReport{Runs: runs} dbConn := c.Database.DB() + logger := loggerFromCtx(ctx, c.Logger) hourlyStart, hourlyEnd, err := latestDailyWindowFromHourlyCache(ctx, dbConn) if err != nil { return report, err } if !hourlyStart.IsZero() { + if logger != nil { + logger.Info("canonical benchmark phase starting", "phase", "daily", "window_start", hourlyStart.Format(time.RFC3339), "window_end", hourlyEnd.Format(time.RFC3339), "runs", runs) + } report.DailyWindowStart = hourlyStart report.DailyWindowEnd = hourlyEnd goDurations := make([]time.Duration, 0, runs) sqlDurations := make([]time.Duration, 0, runs) var goRows, sqlRows int64 for i := 0; i < runs; i++ { + run := i + 1 + if logger != nil { + logger.Info("canonical benchmark run starting", "phase", "daily", "mode", "go", "run", run, "runs", runs) + } dur, rows, runErr := c.benchmarkDailyGoCore(ctx, hourlyStart, hourlyEnd) if runErr != nil { return report, fmt.Errorf("daily go benchmark run %d failed: %w", i+1, runErr) } + if logger != nil { + logger.Info("canonical benchmark run complete", "phase", "daily", "mode", "go", "run", run, "runs", runs, "duration", dur, "rows", rows) + } goDurations = append(goDurations, dur) goRows = rows + if logger != nil { + logger.Info("canonical benchmark run starting", "phase", "daily", "mode", "sql", "run", run, "runs", runs) + } dur, rows, runErr = c.benchmarkDailySQLCore(ctx, hourlyStart, hourlyEnd) if runErr != nil { return report, fmt.Errorf("daily sql benchmark run %d failed: %w", i+1, runErr) } + if logger != nil { + logger.Info("canonical benchmark run complete", "phase", "daily", "mode", "sql", "run", run, "runs", runs, "duration", dur, "rows", rows) + } sqlDurations = append(sqlDurations, dur) sqlRows = rows } @@ -74,6 +91,11 @@ func (c *CronTask) RunCanonicalAggregationBenchmark(ctx context.Context, runs in report.DailySQL = summarizeDurations(sqlDurations) report.DailyGoRowsWritten = goRows report.DailySQLRowsWritten = sqlRows + if logger != nil { + logger.Info("canonical benchmark phase complete", "phase", "daily", "runs", runs) + } + } else if logger != nil { + logger.Info("canonical benchmark phase skipped", "phase", "daily", "reason", "no benchmarkable window found in vm_hourly_stats") } monthlyStart, monthlyEnd, err := latestMonthlyWindowFromDailyRollup(ctx, dbConn) @@ -81,23 +103,39 @@ func (c *CronTask) RunCanonicalAggregationBenchmark(ctx context.Context, runs in return report, err } if !monthlyStart.IsZero() { + if logger != nil { + logger.Info("canonical benchmark phase starting", "phase", "monthly", "window_start", monthlyStart.Format(time.RFC3339), "window_end", monthlyEnd.Format(time.RFC3339), "runs", runs) + } report.MonthlyWindowStart = monthlyStart report.MonthlyWindowEnd = monthlyEnd goDurations := make([]time.Duration, 0, runs) sqlDurations := make([]time.Duration, 0, runs) var goRows, sqlRows int64 for i := 0; i < runs; i++ { + run := i + 1 + if logger != nil { + logger.Info("canonical benchmark run starting", "phase", "monthly", "mode", "go", "run", run, "runs", runs) + } dur, rows, runErr := c.benchmarkMonthlyGoCore(ctx, monthlyStart, monthlyEnd) if runErr != nil { return report, fmt.Errorf("monthly go benchmark run %d failed: %w", i+1, runErr) } + if logger != nil { + logger.Info("canonical benchmark run complete", "phase", "monthly", "mode", "go", "run", run, "runs", runs, "duration", dur, "rows", rows) + } goDurations = append(goDurations, dur) goRows = rows + if logger != nil { + logger.Info("canonical benchmark run starting", "phase", "monthly", "mode", "sql", "run", run, "runs", runs) + } dur, rows, runErr = c.benchmarkMonthlySQLCore(ctx, monthlyStart, monthlyEnd) if runErr != nil { return report, fmt.Errorf("monthly sql benchmark run %d failed: %w", i+1, runErr) } + if logger != nil { + logger.Info("canonical benchmark run complete", "phase", "monthly", "mode", "sql", "run", run, "runs", runs, "duration", dur, "rows", rows) + } sqlDurations = append(sqlDurations, dur) sqlRows = rows } @@ -105,6 +143,11 @@ func (c *CronTask) RunCanonicalAggregationBenchmark(ctx context.Context, runs in report.MonthlySQL = summarizeDurations(sqlDurations) report.MonthlyGoRowsWritten = goRows report.MonthlySQLRowsWritten = sqlRows + if logger != nil { + logger.Info("canonical benchmark phase complete", "phase", "monthly", "runs", runs) + } + } else if logger != nil { + logger.Info("canonical benchmark phase skipped", "phase", "monthly", "reason", "no benchmarkable window found in vm_daily_rollup") } if report.DailyWindowStart.IsZero() && report.MonthlyWindowStart.IsZero() {