progress: support rendering trackers that haven't started yet

Author: NathanBaulch

cmd/demo-progress/demo.go

@@ -23,6 +23,7 @@ var (
 	flagShowSpeedOverall   = flag.Bool("show-speed-overall", false, "Show the overall tracker speed?")
 	flagShowPinned         = flag.Bool("show-pinned", false, "Show a pinned message?")
 	flagRandomFail         = flag.Bool("rnd-fail", false, "Introduce random failures in tracking")
+	flagRandomDefer        = flag.Bool("rnd-defer", false, "Introduce random deferred starts")
 	flagRandomLogs         = flag.Bool("rnd-logs", false, "Output random logs in the middle of tracking")
 
 	messageColors = []text.Color{
@@ -71,13 +72,18 @@ func trackSomething(pw progress.Writer, idx int64, updateMessage bool) {
 
 	units := getUnits(idx)
 	message := getMessage(idx, units)
-	tracker := progress.Tracker{Message: message, Total: total, Units: *units}
+	tracker := progress.Tracker{Message: message, Total: total, Units: *units, DeferStart: *flagRandomDefer && rand.Float64() < 0.5}
 	if idx == int64(*flagNumTrackers) {
 		tracker.Total = 0
 	}
 
 	pw.AppendTracker(&tracker)
 
+	if tracker.DeferStart {
+		time.Sleep(3 * time.Second)
+		tracker.Start()
+	}
+
 	ticker := time.Tick(time.Millisecond * 500)
 	updateTicker := time.Tick(time.Millisecond * 250)
 	for !tracker.IsDone() {

progress/progress.go

@@ -67,7 +67,9 @@ const (
 // to a queue, which gets picked up by the Render logic in the next rendering
 // cycle.
 func (p *Progress) AppendTracker(t *Tracker) {
-	t.start()
+	if !t.DeferStart {
+		t.start()
+	}
 	p.overallTrackerMutex.Lock()
 	defer p.overallTrackerMutex.Unlock()
 

progress/render.go

@@ -93,7 +93,7 @@ func (p *Progress) extractDoneAndActiveTrackers() ([]*Tracker, []*Tracker) {
 
 func (p *Progress) generateTrackerStr(t *Tracker, maxLen int, hint renderHint) string {
 	value, total := t.valueAndTotal()
-	if !hint.isOverallTracker && (total == 0 || value > total) {
+	if !hint.isOverallTracker && t.IsStarted() && (total == 0 || value > total) {
 		return p.generateTrackerStrIndeterminate(maxLen)
 	}
 	return p.generateTrackerStrDeterminate(value, total, maxLen)
@@ -382,14 +382,16 @@ func (p *Progress) renderTrackerStatsSpeed(out *strings.Builder, t *Tracker, hin
 
 		p.trackersActiveMutex.RLock()
 		for _, tracker := range p.trackersActive {
-			speed += float64(tracker.Value()) / time.Since(tracker.timeStart).Round(speedPrecision).Seconds()
+			if !tracker.timeStart.IsZero() {
+				speed += float64(tracker.Value()) / time.Since(tracker.timeStart).Round(speedPrecision).Seconds()
+			}
 		}
 		p.trackersActiveMutex.RUnlock()
 
 		if speed > 0 {
 			p.renderTrackerStatsSpeedInternal(out, p.style.Options.SpeedOverallFormatter(int64(speed)))
 		}
-	} else {
+	} 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())))
@@ -412,7 +414,7 @@ func (p *Progress) renderTrackerStatsTime(outStats *strings.Builder, t *Tracker,
 	var td, tp time.Duration
 	if t.IsDone() {
 		td = t.timeStop.Sub(t.timeStart)
-	} else {
+	} else if !t.timeStart.IsZero() {
 		td = time.Since(t.timeStart)
 	}
 	if hint.isOverallTracker {

progress/render_test.go

@@ -66,6 +66,28 @@ func trackSomething(pw Writer, tracker *Tracker) {
 	}
 }
 
+func trackSomethingDeferred(pw Writer, tracker *Tracker) {
+	incrementPerCycle := tracker.Total / 3
+	tracker.DeferStart = true
+
+	pw.AppendTracker(tracker)
+	skip := true
+
+	c := time.Tick(trackerIncrementInterval)
+	for !tracker.IsDone() {
+		select {
+		case <-c:
+			if skip {
+				skip = false
+			} else if tracker.value+incrementPerCycle > tracker.Total {
+				tracker.Increment(tracker.Total - tracker.value)
+			} else {
+				tracker.Increment(incrementPerCycle)
+			}
+		}
+	}
+}
+
 func trackSomethingErrored(pw Writer, tracker *Tracker) {
 	incrementPerCycle := tracker.Total / 3
 	total := tracker.Total
@@ -279,118 +301,37 @@ func TestProgress_generateTrackerStr_Indeterminate(t *testing.T) {
 	}
 
 	expectedTrackerStrMap := map[int64]string{
-		0:   "<=>.......",
-		1:   ".<=>......",
-		2:   "..<=>.....",
-		3:   "...<=>....",
-		4:   "....<=>...",
-		5:   ".....<=>..",
-		6:   "......<=>.",
-		7:   ".......<=>",
-		8:   "......<=>.",
-		9:   ".....<=>..",
-		10:  "....<=>...",
-		11:  "...<=>....",
-		12:  "..<=>.....",
-		13:  ".<=>......",
-		14:  "<=>.......",
-		15:  ".<=>......",
-		16:  "..<=>.....",
-		17:  "...<=>....",
-		18:  "....<=>...",
-		19:  ".....<=>..",
-		20:  "......<=>.",
-		21:  ".......<=>",
-		22:  "......<=>.",
-		23:  ".....<=>..",
-		24:  "....<=>...",
-		25:  "...<=>....",
-		26:  "..<=>.....",
-		27:  ".<=>......",
-		28:  "<=>.......",
-		29:  ".<=>......",
-		30:  "..<=>.....",
-		31:  "...<=>....",
-		32:  "....<=>...",
-		33:  ".....<=>..",
-		34:  "......<=>.",
-		35:  ".......<=>",
-		36:  "......<=>.",
-		37:  ".....<=>..",
-		38:  "....<=>...",
-		39:  "...<=>....",
-		40:  "..<=>.....",
-		41:  ".<=>......",
-		42:  "<=>.......",
-		43:  ".<=>......",
-		44:  "..<=>.....",
-		45:  "...<=>....",
-		46:  "....<=>...",
-		47:  ".....<=>..",
-		48:  "......<=>.",
-		49:  ".......<=>",
-		50:  "......<=>.",
-		51:  ".....<=>..",
-		52:  "....<=>...",
-		53:  "...<=>....",
-		54:  "..<=>.....",
-		55:  ".<=>......",
-		56:  "<=>.......",
-		57:  ".<=>......",
-		58:  "..<=>.....",
-		59:  "...<=>....",
-		60:  "....<=>...",
-		61:  ".....<=>..",
-		62:  "......<=>.",
-		63:  ".......<=>",
-		64:  "......<=>.",
-		65:  ".....<=>..",
-		66:  "....<=>...",
-		67:  "...<=>....",
-		68:  "..<=>.....",
-		69:  ".<=>......",
-		70:  "<=>.......",
-		71:  ".<=>......",
-		72:  "..<=>.....",
-		73:  "...<=>....",
-		74:  "....<=>...",
-		75:  ".....<=>..",
-		76:  "......<=>.",
-		77:  ".......<=>",
-		78:  "......<=>.",
-		79:  ".....<=>..",
-		80:  "....<=>...",
-		81:  "...<=>....",
-		82:  "..<=>.....",
-		83:  ".<=>......",
-		84:  "<=>.......",
-		85:  ".<=>......",
-		86:  "..<=>.....",
-		87:  "...<=>....",
-		88:  "....<=>...",
-		89:  ".....<=>..",
-		90:  "......<=>.",
-		91:  ".......<=>",
-		92:  "......<=>.",
-		93:  ".....<=>..",
-		94:  "....<=>...",
-		95:  "...<=>....",
-		96:  "..<=>.....",
-		97:  ".<=>......",
-		98:  "<=>.......",
-		99:  ".<=>......",
-		100: "..<=>.....",
+		-1: "..........",
+		0:  "<=>.......",
+		1:  ".<=>......",
+		2:  "..<=>.....",
+		3:  "...<=>....",
+		4:  "....<=>...",
+		5:  ".....<=>..",
+		6:  "......<=>.",
+		7:  ".......<=>",
+		8:  "......<=>.",
+		9:  ".....<=>..",
+		10: "....<=>...",
+		11: "...<=>....",
+		12: "..<=>.....",
+		13: ".<=>......",
 	}
 
 	finalOutput := strings.Builder{}
 	tr := Tracker{Total: 0}
-	for value := int64(0); value <= 100; value++ {
-		tr.value = value
+	for value := int64(-1); value <= 100; value++ {
+		if value >= 0 {
+			tr.value = value
+		}
 		actualStr := pw.generateTrackerStr(&tr, 10, renderHint{})
-		if expectedStr, ok := expectedTrackerStrMap[value]; ok {
+		if expectedStr, ok := expectedTrackerStrMap[value%14]; ok {
 			assert.Equal(t, expectedStr, actualStr, "value=%d", value)
 		}
 		finalOutput.WriteString(fmt.Sprintf(" %d: \"%s\",\n", value, actualStr))
+		if value < 0 {
+			tr.timeStart = time.Now()
+		}
 	}
 	if t.Failed() {
 		fmt.Println(finalOutput.String())
@@ -496,6 +437,35 @@ func TestProgress_RenderSomeTrackers_WithAutoStop(t *testing.T) {
 	showOutputOnFailure(t, out)
 }
 
+func TestProgress_RenderSomeTrackers_DeferStart(t *testing.T) {
+	renderOutput := outputWriter{}
+
+	pw := generateWriter()
+	pw.Style().Visibility.Speed = true
+	pw.SetOutputWriter(&renderOutput)
+	go trackSomething(pw, &Tracker{Message: "Calculating Total   # 1\r", Total: 1000, Units: UnitsDefault})
+	go trackSomething(pw, &Tracker{Message: "Downloading File\t# 2", Total: 1000, Units: UnitsBytes})
+	go trackSomethingDeferred(pw, &Tracker{Message: "Transferring Amount # 3", Total: 1000, Units: UnitsCurrencyDollar})
+	renderAndWait(pw, false)
+
+	expectedOutPatterns := []*regexp.Regexp{
+		regexp.MustCompile(`Transferring Amount # 3 \.\.\. +0.00% \[\.{23}] \[\$0 in 0s]`),
+		regexp.MustCompile(`Calculating Total   # 1 \.\.\. \d+\.\d+% \[[#.]{23}] \[\d+ in [\d.]+ms; \d+\.\d+\w+/s]`),
+		regexp.MustCompile(`Downloading File    # 2 \.\.\. \d+\.\d+% \[[#.]{23}] \[\d+B in [\d.]+ms; \d+\.\d+\w+/s]`),
+		regexp.MustCompile(`Transferring Amount # 3 \.\.\. \d+\.\d+% \[[<#>.]{23}] \[\$\d+ in [\d.]+ms; \$\d+\.\d+\w+/s]`),
+		regexp.MustCompile(`Calculating Total   # 1 \.\.\. done! \[\d+\.\d+K in [\d.]+ms; \d+\.\d+\w+/s]`),
+		regexp.MustCompile(`Downloading File    # 2 \.\.\. done! \[\d+\.\d+KB in [\d.]+ms; \d+\.\d+\w+/s]`),
+		regexp.MustCompile(`Transferring Amount # 3 \.\.\. done! \[\$\d+\.\d+K in [\d.]+ms; \$\d+\.\d+\w+/s]`),
+	}
+	out := renderOutput.String()
+	for _, expectedOutPattern := range expectedOutPatterns {
+		if !expectedOutPattern.MatchString(out) {
+			assert.Fail(t, "Failed to find a pattern in the Output.", expectedOutPattern.String())
+		}
+	}
+	showOutputOnFailure(t, out)
+}
+
 func TestProgress_RenderSomeTrackers_WithError(t *testing.T) {
 	renderOutput := outputWriter{}
 

progress/tracker.go

@@ -25,6 +25,8 @@ type Tracker struct {
 	// Units defines the type of the "value" being tracked
 	Units Units
 
+	DeferStart bool
+
 	done      bool
 	err       bool
 	mutex     sync.RWMutex
@@ -39,6 +41,10 @@ func (t *Tracker) ETA() time.Duration {
 	t.mutex.RLock()
 	defer t.mutex.RUnlock()
 
+	if t.timeStart.IsZero() {
+		return time.Duration(0)
+	}
+
 	timeTaken := time.Since(t.timeStart)
 	if t.ExpectedDuration > time.Duration(0) && t.ExpectedDuration > timeTaken {
 		return t.ExpectedDuration - timeTaken
@@ -67,6 +73,15 @@ func (t *Tracker) IncrementWithError(value int64) {
 	t.mutex.Unlock()
 }
 
+// IsStarted true if the tracker has started, false when using DeferStart
+// prior to Start, Increment, IncrementWithError or SetValue being called.
+func (t *Tracker) IsStarted() bool {
+	t.mutex.RLock()
+	defer t.mutex.RUnlock()
+
+	return !t.timeStart.IsZero()
+}
+
 // IsDone returns true if the tracker is done (value has reached the expected
 // Total set during initialization).
 func (t *Tracker) IsDone() bool {
@@ -191,22 +206,35 @@ func (t *Tracker) valueAndTotal() (int64, int64) {
 
 func (t *Tracker) incrementWithoutLock(value int64) {
 	if !t.done {
+		if t.timeStart.IsZero() {
+			t.startWithoutLock()
+		}
 		t.value += value
 		if t.Total > 0 && t.value >= t.Total {
 			t.stop()
 		}
 	}
 }
 
+func (t *Tracker) Start() {
+	if t.timeStart.IsZero() {
+		t.start()
+	}
+}
+
 func (t *Tracker) start() {
 	t.mutex.Lock()
+	t.startWithoutLock()
+	t.mutex.Unlock()
+}
+
+func (t *Tracker) startWithoutLock() {
 	if t.Total < 0 {
 		t.Total = math.MaxInt64
 	}
 	t.done = false
 	t.err = false
 	t.timeStart = time.Now()
-	t.mutex.Unlock()
 }
 
 // this must be called with the mutex held with a write lock

progress/tracker_test.go

@@ -68,6 +68,28 @@ func TestTracker_IncrementWithError(t *testing.T) {
 	assert.True(t, tracker.IsDone())
 }
 
+func TestTracker_IsStarted(t *testing.T) {
+	tracker := Tracker{DeferStart: true}
+	assert.False(t, tracker.IsStarted())
+	tracker.Start()
+	assert.True(t, tracker.IsStarted())
+
+	tracker = Tracker{DeferStart: true}
+	assert.False(t, tracker.IsStarted())
+	tracker.Increment(1)
+	assert.True(t, tracker.IsStarted())
+
+	tracker = Tracker{DeferStart: true}
+	assert.False(t, tracker.IsStarted())
+	tracker.IncrementWithError(1)
+	assert.True(t, tracker.IsStarted())
+
+	tracker = Tracker{DeferStart: true}
+	assert.False(t, tracker.IsStarted())
+	tracker.SetValue(1)
+	assert.True(t, tracker.IsStarted())
+}
+
 func TestTracker_IsDone(t *testing.T) {
 	tracker := Tracker{Total: 10}
 	assert.False(t, tracker.IsDone())