Bug 1425438 - use wall time durations rather than monotonic clock dur…

…ations in time arithmetic

main.go

@@ -576,7 +576,8 @@ func RunWorker() (exitCode ExitCode) {
 
 		// See https://bugzil.la/1298010 - routinely check if this worker type is
 		// outdated, and shut down if a new deployment is required.
-		if configureForAws && time.Now().Sub(lastQueriedProvisioner) > time.Duration(config.CheckForNewDeploymentEverySecs)*time.Second {
+		// Round(0) forces wall time calculation instead of monotonic time in case machine slept etc
+		if configureForAws && time.Now().Round(0).Sub(lastQueriedProvisioner) > time.Duration(config.CheckForNewDeploymentEverySecs)*time.Second {
 			lastQueriedProvisioner = time.Now()
 			if deploymentIDUpdated() {
 				return NONCURRENT_DEPLOYMENT_ID
@@ -612,7 +613,8 @@ func RunWorker() (exitCode ExitCode) {
 				return REBOOT_REQUIRED
 			}
 		} else {
-			idleTime := time.Now().Sub(lastActive)
+			// Round(0) forces wall time calculation instead of monotonic time in case machine slept etc
+			idleTime := time.Now().Round(0).Sub(lastActive)
 			remainingIdleTimeText := ""
 			if config.IdleTimeoutSecs > 0 {
 				remainingIdleTimeText = fmt.Sprintf(" (will exit if no task claimed in %v)", time.Second*time.Duration(config.IdleTimeoutSecs)-idleTime)
@@ -622,9 +624,10 @@ func RunWorker() (exitCode ExitCode) {
 					return IDLE_TIMEOUT
 				}
 			}
-			// let's not be over-verbose in logs - has cost implications
-			// so report only once per minute that no task was claimed, not every second
-			if time.Now().Sub(lastReportedNoTasks) > 1*time.Minute {
+			// Let's not be over-verbose in logs - has cost implications,
+			// so report only once per minute that no task was claimed, not every second.
+			// Round(0) forces wall time calculation instead of monotonic time in case machine slept etc
+			if time.Now().Round(0).Sub(lastReportedNoTasks) > 1*time.Minute {
 				lastReportedNoTasks = time.Now()
 				// remainingTasks will be -ve, if config.NumberOfTasksToRun is not set (=0)
 				remainingTaskCountText := ""
@@ -731,7 +734,8 @@ func (task *TaskRun) setReclaimTimer() {
 	// Attempt to reclaim 3 mins earlier...
 	reclaimTime := takenUntil.Add(time.Minute * -3)
 	log.Printf("Reclaiming 3 mins earlier, at %v", reclaimTime)
-	waitTimeUntilReclaim := reclaimTime.Sub(time.Now())
+	// Round(0) forces wall time calculation instead of monotonic time in case machine slept etc
+	waitTimeUntilReclaim := reclaimTime.Round(0).Sub(time.Now())
 	log.Printf("Time to wait until then is %v", waitTimeUntilReclaim)
 	// sanity check - only set an alarm, if wait time > 30s, so we can't hammer queue
 	if waitTimeUntilReclaim.Seconds() > 30 {
@@ -950,7 +954,8 @@ func (task *TaskRun) setMaxRunTimer() *time.Timer {
 	// resolve the run as exception and create a new run, if the task has
 	// additional retries left.
 	return time.AfterFunc(
-		task.maxRunTimeDeadline.Sub(time.Now()),
+		// Round(0) forces wall time calculation instead of monotonic time in case machine slept etc
+		task.maxRunTimeDeadline.Round(0).Sub(time.Now()),
 		func() {
 			// ignore any error - in the wrong go routine to properly handle it
 			task.StatusManager.Abort()
@@ -1138,7 +1143,8 @@ func (task *TaskRun) Run() (err *executionErrors) {
 	defer func() {
 		finished := time.Now()
 		task.Log("=== Task Finished ===")
-		task.Log("Task Duration: " + finished.Sub(started).String())
+		// Round(0) forces wall time calculation instead of monotonic time in case machine slept etc
+		task.Log("Task Duration: " + finished.Round(0).Sub(started).String())
 	}()
 
 	for i := range task.Payload.Command {

main_test.go

@@ -73,7 +73,8 @@ func TestIdleWithoutCrash(t *testing.T) {
 	if exitCode != IDLE_TIMEOUT {
 		t.Fatalf("Was expecting exit code %v, but got exit code %v", IDLE_TIMEOUT, exitCode)
 	}
-	if secsAlive := end.Sub(start).Seconds(); secsAlive < 7 {
+	// Round(0) forces wall time calculation instead of monotonic time in case machine slept etc
+	if secsAlive := end.Round(0).Sub(start).Seconds(); secsAlive < 7 {
 		t.Fatalf("Worker died early - lasted for %v seconds", secsAlive)
 	}
 }

mounts.go

@@ -674,7 +674,8 @@ func (taskMount *TaskMount) purgeCaches() error {
 			writableCaches = append(writableCaches, t)
 		}
 	}
-	if len(writableCaches) == 0 && time.Now().Sub(lastQueriedPurgeCacheService) < 6*time.Hour {
+	// Round(0) forces wall time calculation instead of monotonic time in case machine slept etc
+	if len(writableCaches) == 0 && time.Now().Round(0).Sub(lastQueriedPurgeCacheService) < 6*time.Hour {
 		return nil
 	}
 	// In case of clock drift, let's query all purge cache requests created

process/process_all-unix-style.go

@@ -81,7 +81,8 @@ func (c *Command) Execute() (r *Result) {
 	}
 	err = c.Wait()
 	finished := time.Now()
-	r.Duration = finished.Sub(started)
+	// Round(0) forces wall time calculation instead of monotonic time in case machine slept etc
+	r.Duration = finished.Round(0).Sub(started)
 	if err != nil {
 		if exiterr, ok := err.(*exec.ExitError); ok {
 			r.ExitError = exiterr

process/process_windows.go

@@ -121,7 +121,8 @@ func (c *Command) String() string {
 
 func (c *Command) Execute() (r *Result) {
 	if !c.Deadline.IsZero() {
-		c.HardTimeLimit = c.Deadline.Sub(time.Now())
+		// Round(0) forces wall time calculation instead of monotonic time in case machine slept etc
+		c.HardTimeLimit = c.Deadline.Round(0).Sub(time.Now())
 		if c.HardTimeLimit < 0 {
 			log.Printf("WARNING: Deadline %v exceeded before command %v has been executed!", c.Deadline, c)
 			// this is a hack to simulate a failure