Merge pull request #1736 from molecula/time-estimate-rules

SUP-75: Change time estimation to use avg time per message

.gitignore

@@ -11,3 +11,4 @@ release-pilosa-fsck.*.*.tar.gz
 pilosa
 *.dot
 .idea/
+.*.swp

server.go

@@ -703,6 +703,7 @@ func (s *Server) Open() error {
 
 		start := time.Now()
 		prevMsg := start
+		numMsgs := uint(len(toSend))
 		s.logger.Printf("start initial cluster state sync")
 		for i := range toSend {
 			for {
@@ -721,10 +722,8 @@ func (s *Server) Open() error {
 			}
 
 			if now := time.Now(); now.Sub(prevMsg) > time.Second {
-				progressRatio := float64(i+1) / float64(len(toSend))
-				remainingRatio := 1 - progressRatio
-				timeRemaining := time.Duration(float64(now.Sub(prevMsg)) * (remainingRatio / progressRatio))
-				s.logger.Printf("synced %d/%d messages (%.2f%% complete; %s remaining)", i+1, len(toSend), 100*progressRatio, timeRemaining)
+				estimate, pctDone := GetLoopProgress(start, now, uint(i), numMsgs)
+				s.logger.Printf("synced %d/%d messages (%.2f%% complete; %s remaining)", i+1, numMsgs, pctDone, estimate)
 				prevMsg = now
 			}
 		}

util.go

@@ -25,6 +25,7 @@ import (
 	"sort"
 	"strings"
 	"syscall"
+	"time"
 	"unsafe"
 
 	"github.com/molecula/featurebase/v2/roaring"
@@ -343,3 +344,13 @@ func roaringFragmentHasData(path string, index, field, view string, shard uint64
 
 	return
 }
+
+// GetLoopProgress returns the estimated remaining time to iterate through some items
+// as well as the loop completion percentage with the following parameters:
+// the start time, the current time, the iteration, and the number of items
+func GetLoopProgress(start time.Time, now time.Time, iteration uint, total uint) (remaining time.Duration, pctDone float64) {
+	itemsLeft := total - (iteration + 1)
+	avgItemTime := float64(now.Sub(start)) / float64(iteration+1)
+	pctDone = (float64(iteration+1) / float64(total)) * 100
+	return time.Duration(avgItemTime * float64(itemsLeft)), pctDone
+}

util_test.go

@@ -0,0 +1,87 @@
+// Copyright 2021 Pilosa Corp.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+package pilosa
+
+// util_test.go has unit tests for utility functions from util.go
+//
+
+import (
+	"testing"
+	"time"
+)
+
+func TestGetLoopProgress(t *testing.T) {
+	// TODO: try to find more sneaky cases
+	cases := []struct {
+		name  string
+		start time.Time
+		now   time.Time
+		i     uint
+		total uint
+	}{
+		{
+			"one minute, half done",
+			time.Date(1969, time.June, 9, 4, 20, 0, 0, time.UTC),
+			time.Date(1969, time.June, 9, 4, 21, 0, 0, time.UTC),
+			10,
+			20,
+		},
+		{
+			"four seconds, half done",
+			time.Date(1969, time.June, 9, 4, 20, 0, 0, time.UTC),
+			time.Date(1969, time.June, 9, 4, 20, 4, 0, time.UTC),
+			10,
+			20,
+		},
+		{
+			"one minute, one second, 5 μs, half done",
+			time.Date(1969, time.June, 9, 4, 20, 0, 0, time.UTC),
+			time.Date(1969, time.June, 9, 4, 21, 1, 5, time.UTC),
+			10,
+			20,
+		},
+		{
+			"one minute, one done",
+			time.Date(1969, time.June, 9, 4, 20, 0, 0, time.UTC),
+			time.Date(1969, time.June, 9, 4, 21, 0, 0, time.UTC),
+			1,
+			20,
+		},
+		{
+			"one minute, 1/5 done",
+			time.Date(1969, time.June, 9, 4, 20, 0, 0, time.UTC),
+			time.Date(1969, time.June, 9, 4, 21, 0, 0, time.UTC),
+			10,
+			50,
+		},
+	}
+
+	for _, c := range cases {
+		t.Run(c.name, func(t *testing.T) {
+			// we expect that it will be the avg time per message times
+			// the number of remaining messages
+			expected := time.Duration((float64(c.now.Sub(c.start)) / float64(c.i+1)) * float64(c.total-(c.i+1)))
+			expectedPct := 100 * (float64(c.i+1) / float64(c.total))
+
+			timeLeft, pctDone := GetLoopProgress(c.start, c.now, c.i, c.total)
+			if timeLeft != expected {
+				t.Errorf("Time left was incorrect, expected: %d, but got: %d", expected, timeLeft)
+			}
+			if pctDone != expectedPct {
+				t.Errorf("Percentage done was incorrect, expected: %f, but got: %f", expectedPct, pctDone)
+			}
+		})
+	}
+}