progress: address race conditions in render/stop/trackers; fixes 399 (#401)

Author: jedib0t

Makefile

@@ -26,9 +26,10 @@ test: fmt vet lint cyclo
 test-no-lint: fmt vet cyclo
 	go test -cover -coverprofile=.coverprofile ./...
 
-## test-race: Run progress demo with race detector
+## test-race: Run tests and progress demo with race detector
 test-race:
-	go run -race ./cmd/demo-progress/demo.go
+	go test -race ./...
+	go run -race ./cmd/demo-progress
 
 # ============================================================================
 # Code quality targets

progress/README.md

@@ -26,11 +26,17 @@ A demonstration of all the capabilities can be found here:
 ### Tracker Management
 
   - Dynamically add one or more Task Trackers while `Render()` is in progress
-  - Sort trackers by Message, Percentage, or Value (ascending/descending)
+  - Sort trackers by Index (ascending/descending), Message, Percentage, or Value
+    - `SortByIndex` / `SortByIndexDsc` - Sort by explicit Index field, maintaining
+      order regardless of completion status (done and active trackers are merged
+      and sorted together)
+    - For other sorting methods, done and active trackers are sorted separately,
+      with done trackers always rendered before active trackers
   - Tracker options
+    - `AutoStopDisabled` - Prevent auto-completion when value exceeds total
     - `DeferStart` - Delay tracker start until manually triggered
+    - `Index` - Explicit ordering value for trackers (used with `SortByIndex`)
     - `RemoveOnCompletion` - Hide tracker when done instead of showing completion
-    - `AutoStopDisabled` - Prevent auto-completion when value exceeds total
 
 ### Display & Rendering
 

progress/progress.go

@@ -32,6 +32,7 @@ type Progress struct {
 	logsToRenderMutex        sync.RWMutex
 	numTrackersExpected      int64
 	outputWriter             io.Writer
+	outputWriterMutex        sync.RWMutex
 	overallTracker           *Tracker
 	overallTrackerMutex      sync.RWMutex
 	pinnedMessages           []string
@@ -199,7 +200,9 @@ func (p *Progress) SetNumTrackersExpected(numTrackers int) {
 // os.Stdout or os.Stderr or a file. Warning: redirecting the output to a file
 // may not work well as the Render() logic moves the cursor around a lot.
 func (p *Progress) SetOutputWriter(writer io.Writer) {
+	p.outputWriterMutex.Lock()
 	p.outputWriter = writer
+	p.outputWriterMutex.Unlock()
 }
 
 // SetPinnedMessages sets message(s) pinned above all the trackers of the
@@ -344,16 +347,19 @@ func (p *Progress) initForRender() {
 	}
 
 	// if not output write has been set, output to STDOUT
+	p.outputWriterMutex.RLock()
 	if p.outputWriter == nil {
 		p.outputWriter = os.Stdout
 	}
+	outputWriter := p.outputWriter
+	p.outputWriterMutex.RUnlock()
 
 	// pick a sane update frequency if none set
 	if p.updateFrequency <= 0 {
 		p.updateFrequency = DefaultUpdateFrequency
 	}
 
-	if p.outputWriter == os.Stdout {
+	if outputWriter == os.Stdout {
 		// get the current terminal size for preventing roll-overs, and do this in a
 		// background loop until end of render. This only works if the output writer is STDOUT.
 		go p.watchTerminalSize() // needs p.updateFrequency

progress/render.go

@@ -382,11 +382,17 @@ func (p *Progress) renderTrackers(lastRenderLength int) int {
 	}
 
 	// write the text to the output writer
+	p.outputWriterMutex.Lock()
 	_, _ = p.outputWriter.Write([]byte(out.String()))
+	p.outputWriterMutex.Unlock()
 
 	// stop if auto stop is enabled and there are no more active trackers
 	if p.autoStop && p.LengthActive() == 0 {
-		p.renderContextCancel()
+		p.renderContextCancelMutex.Lock()
+		if p.renderContextCancel != nil {
+			p.renderContextCancel()
+		}
+		p.renderContextCancelMutex.Unlock()
 	}
 
 	return out.Len()
@@ -498,19 +504,23 @@ func (p *Progress) renderTrackerStatsSpeed(out *strings.Builder, t *Tracker, hin
 
 		p.trackersActiveMutex.RLock()
 		for _, tracker := range p.trackersActive {
-			if !tracker.timeStart.IsZero() {
-				speed += float64(tracker.Value()) / time.Since(tracker.timeStart).Round(speedPrecision).Seconds()
+			timeStart := tracker.timeStartValue()
+			if !timeStart.IsZero() {
+				speed += float64(tracker.Value()) / time.Since(timeStart).Round(speedPrecision).Seconds()
 			}
 		}
 		p.trackersActiveMutex.RUnlock()
 
 		if speed > 0 {
 			p.renderTrackerStatsSpeedInternal(out, p.style.Options.SpeedOverallFormatter(int64(speed)))
 		}
-	} else if !t.timeStart.IsZero() {
-		timeTaken := time.Since(t.timeStart)
-		if timeTakenRounded := timeTaken.Round(speedPrecision); timeTakenRounded > speedPrecision {
-			p.renderTrackerStatsSpeedInternal(out, t.Units.Sprint(int64(float64(t.Value())/timeTakenRounded.Seconds())))
+	} else {
+		timeStart := t.timeStartValue()
+		if !timeStart.IsZero() {
+			timeTaken := time.Since(timeStart)
+			if timeTakenRounded := timeTaken.Round(speedPrecision); timeTakenRounded > speedPrecision {
+				p.renderTrackerStatsSpeedInternal(out, t.Units.Sprint(int64(float64(t.Value())/timeTakenRounded.Seconds())))
+			}
 		}
 	}
 }
@@ -528,11 +538,12 @@ func (p *Progress) renderTrackerStatsSpeedInternal(out *strings.Builder, speed s
 
 func (p *Progress) renderTrackerStatsTime(outStats *strings.Builder, t *Tracker, hint renderHint) {
 	var td, tp time.Duration
-	if !t.timeStart.IsZero() {
+	timeStart, timeStop := t.timeStartAndStop()
+	if !timeStart.IsZero() {
 		if t.IsDone() {
-			td = t.timeStop.Sub(t.timeStart)
+			td = timeStop.Sub(timeStart)
 		} else {
-			td = time.Since(t.timeStart)
+			td = time.Since(timeStart)
 		}
 	}
 	if hint.isOverallTracker {

progress/render_test.go

@@ -5,6 +5,7 @@ import (
 	"regexp"
 	"sort"
 	"strings"
+	"sync"
 	"testing"
 	"time"
 
@@ -19,13 +20,18 @@ var (
 
 type outputWriter struct {
 	Text strings.Builder
+	mu   sync.Mutex
 }
 
 func (w *outputWriter) Write(p []byte) (n int, err error) {
+	w.mu.Lock()
+	defer w.mu.Unlock()
 	return w.Text.Write(p)
 }
 
 func (w *outputWriter) String() string {
+	w.mu.Lock()
+	defer w.mu.Unlock()
 	return w.Text.String()
 }
 
@@ -331,7 +337,7 @@ func TestProgress_generateTrackerStr_Indeterminate(t *testing.T) {
 }
 
 func TestProgress_RenderNeverStarted(t *testing.T) {
-	renderOutput := strings.Builder{}
+	renderOutput := outputWriter{}
 
 	pw := generateWriter()
 	pw.SetOutputWriter(&renderOutput)

progress/tracker.go

@@ -264,3 +264,20 @@ func (t *Tracker) valueAndTotal() (int64, int64) {
 	t.mutex.RUnlock()
 	return value, total
 }
+
+// timeStartAndStop returns the start and stop times safely.
+func (t *Tracker) timeStartAndStop() (time.Time, time.Time) {
+	t.mutex.RLock()
+	timeStart := t.timeStart
+	timeStop := t.timeStop
+	t.mutex.RUnlock()
+	return timeStart, timeStop
+}
+
+// timeStartValue returns the start time safely.
+func (t *Tracker) timeStartValue() time.Time {
+	t.mutex.RLock()
+	timeStart := t.timeStart
+	t.mutex.RUnlock()
+	return timeStart
+}

progress/tracker_sort.go

@@ -69,7 +69,7 @@ func (sb sortByIndex) Swap(i, j int) { sb[i], sb[j] = sb[j], sb[i] }
 func (sb sortByIndex) Less(i, j int) bool {
 	if sb[i].Index == sb[j].Index {
 		// Same index: maintain insertion order (use timeStart as tiebreaker)
-		return sb[i].timeStart.Before(sb[j].timeStart)
+		return sb[i].timeStartValue().Before(sb[j].timeStartValue())
 	}
 	return sb[i].Index < sb[j].Index
 }
@@ -81,7 +81,7 @@ func (sb sortByIndexDsc) Swap(i, j int) { sb[i], sb[j] = sb[j], sb[i] }
 func (sb sortByIndexDsc) Less(i, j int) bool {
 	if sb[i].Index == sb[j].Index {
 		// Same index: maintain insertion order (earlier timeStart first)
-		return sb[i].timeStart.Before(sb[j].timeStart)
+		return sb[i].timeStartValue().Before(sb[j].timeStartValue())
 	}
 	// Reverse: higher index comes first
 	return sb[i].Index > sb[j].Index
@@ -100,7 +100,7 @@ func (sb sortByPercent) Swap(i, j int) { sb[i], sb[j] = sb[j], sb[i] }
 func (sb sortByPercent) Less(i, j int) bool {
 	if sb[i].PercentDone() == sb[j].PercentDone() {
 		// When percentages are equal, preserve insertion order (earlier timeStart first)
-		return sb[i].timeStart.Before(sb[j].timeStart)
+		return sb[i].timeStartValue().Before(sb[j].timeStartValue())
 	}
 	return sb[i].PercentDone() < sb[j].PercentDone()
 }
@@ -112,7 +112,7 @@ func (sb sortByPercentDsc) Swap(i, j int) { sb[i], sb[j] = sb[j], sb[i] }
 func (sb sortByPercentDsc) Less(i, j int) bool {
 	if sb[i].PercentDone() == sb[j].PercentDone() {
 		// When percentages are equal, preserve insertion order (earlier timeStart first)
-		return sb[i].timeStart.Before(sb[j].timeStart)
+		return sb[i].timeStartValue().Before(sb[j].timeStartValue())
 	}
 	// Reverse: higher percentage comes first
 	return sb[i].PercentDone() > sb[j].PercentDone()
@@ -123,23 +123,27 @@ type sortByValue []*Tracker
 func (sb sortByValue) Len() int      { return len(sb) }
 func (sb sortByValue) Swap(i, j int) { sb[i], sb[j] = sb[j], sb[i] }
 func (sb sortByValue) Less(i, j int) bool {
-	if sb[i].value == sb[j].value {
-		return sb[i].timeStart.Before(sb[j].timeStart)
+	valueI := sb[i].Value()
+	valueJ := sb[j].Value()
+	if valueI == valueJ {
+		return sb[i].timeStartValue().Before(sb[j].timeStartValue())
 	}
-	return sb[i].value < sb[j].value
+	return valueI < valueJ
 }
 
 type sortByValueDsc []*Tracker
 
 func (sb sortByValueDsc) Len() int      { return len(sb) }
 func (sb sortByValueDsc) Swap(i, j int) { sb[i], sb[j] = sb[j], sb[i] }
 func (sb sortByValueDsc) Less(i, j int) bool {
-	if sb[i].value == sb[j].value {
+	valueI := sb[i].Value()
+	valueJ := sb[j].Value()
+	if valueI == valueJ {
 		// When values are equal, preserve insertion order (earlier timeStart first)
-		return sb[i].timeStart.Before(sb[j].timeStart)
+		return sb[i].timeStartValue().Before(sb[j].timeStartValue())
 	}
 	// Reverse: higher value comes first
-	return sb[i].value > sb[j].value
+	return valueI > valueJ
 }
 
 type sortDsc struct{ sort.Interface }