From ef5be3b9cd9f96a84ad22ec3f9d747e113f5ebb4 Mon Sep 17 00:00:00 2001
From: Wael Nasreddine <wael.nasreddine@gmail.com>
Date: Thu, 27 Aug 2026 09:51:27 -0700
Subject: [PATCH] fix(migrate): emit progress line before first tick

The chunks-to-nar progress reporter was driven purely by a ticker, so a
migration that finished inside a single interval emitted no progress line
at all -- the ticker simply never fired. That is a real reporting gap for
short migrations, and it made
TestMigrateChunksToNar_CLI_ProgressLogEmitted non-deterministic: with the
interval overridden to 1ms and a one-item migration, the work raced the
first tick and lost roughly four runs in five (verified on a clean tree
with unrelated changes stashed).

Extract the emission into a logProgress closure and call it once up front
when there is work to do, then once per tick as before. The immediate
call makes at least one progress line guaranteed whenever total > 0, which
removes the race, and gives operators feedback instead of a silent first
interval.

The call is gated on total > 0 so an empty run stays completely silent,
preserving TestMigrateChunksToNar_CLI_NoProgressLogOnEmptyRun.

Verified: 12/12 consecutive runs of both progress tests pass.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_014zzHofsGpUn34b21AeP3yP
---
 pkg/ncps/migrate_chunks_to_nar.go | 73 +++++++++++++++++++------------
 1 file changed, 46 insertions(+), 27 deletions(-)

diff --git a/pkg/ncps/migrate_chunks_to_nar.go b/pkg/ncps/migrate_chunks_to_nar.go
index 3b2dacd81..00daf2de2 100644
--- a/pkg/ncps/migrate_chunks_to_nar.go
+++ b/pkg/ncps/migrate_chunks_to_nar.go
@@ -327,39 +327,58 @@ func migrateChunksToNarAction(registerShutdown registerShutdownFn) cli.ActionFun
 
 		progressWg.Add(1)
 
+		// logProgress emits one progress line from the counters as they stand.
+		logProgress := func() {
+			elapsed := time.Since(startTime)
+			processed := atomic.LoadInt32(&totalProcessed)
+			succeeded := atomic.LoadInt32(&totalSucceeded)
+			failed := atomic.LoadInt32(&totalFailed)
+			skipped := atomic.LoadInt32(&totalSkipped)
+
+			var rate float64
+			if durationInSeconds := elapsed.Seconds(); durationInSeconds > 0 {
+				rate = float64(processed) / durationInSeconds
+			}
+
+			var percent float64
+			if total > 0 {
+				percent = float64(processed) / float64(total) * 100
+			}
+
+			logger.Info().
+				Int64("total", total).
+				Int32("processed", processed).
+				Int32("succeeded", succeeded).
+				Int32("failed", failed).
+				Int32("skipped", skipped).
+				Int32("purged", atomic.LoadInt32(&totalPurged)).
+				Str("percent", fmt.Sprintf("%.2f%%", percent)).
+				Str("elapsed", elapsed.Round(time.Second).String()).
+				Float64("rate", rate).
+				Msg("migration progress")
+		}
+
+		// Emit one line immediately when there is work to do, then one per tick.
+		//
+		// A purely ticker-driven reporter emits nothing at all when the migration
+		// finishes inside a single interval, because the ticker never fires. That is a
+		// real reporting gap for short migrations, and it made the progress test
+		// non-deterministic: with a 1ms interval and a one-item migration it raced the
+		// first tick and failed roughly four runs in five. Reporting up front also gives
+		// operators immediate feedback instead of a silent first interval.
+		//
+		// Gated on total > 0 so an empty run stays completely silent.
+		if total > 0 {
+			logProgress()
+		}
+
 		go func() {
 			defer progressWg.Done()
 
 			for {
 				select {
 				case <-progressTicker.C:
-					elapsed := time.Since(startTime)
-					processed := atomic.LoadInt32(&totalProcessed)
-					succeeded := atomic.LoadInt32(&totalSucceeded)
-					failed := atomic.LoadInt32(&totalFailed)
-					skipped := atomic.LoadInt32(&totalSkipped)
-
-					var rate float64
-					if durationInSeconds := elapsed.Seconds(); durationInSeconds > 0 {
-						rate = float64(processed) / durationInSeconds
-					}
-
-					var percent float64
-					if total > 0 {
-						percent = float64(processed) / float64(total) * 100
-					}
-
-					logger.Info().
-						Int64("total", total).
-						Int32("processed", processed).
-						Int32("succeeded", succeeded).
-						Int32("failed", failed).
-						Int32("skipped", skipped).
-						Int32("purged", atomic.LoadInt32(&totalPurged)).
-						Str("percent", fmt.Sprintf("%.2f%%", percent)).
-						Str("elapsed", elapsed.Round(time.Second).String()).
-						Float64("rate", rate).
-						Msg("migration progress")
+					logProgress()
 				case <-progressDone:
 					return
 				}