@@ -128,7 +128,7 @@ func TestWorkspaceActivityBump(t *testing.T) {
128128// be increased. Since it could have been bumped at the intial
129129maxTimeDrift := testutil .WaitMedium
130130
131- var updatedAfter time. Time
131+ updatedAfter := dbtime . Now ()
132132// waitedFor is purely for debugging failed tests. If a test fails,
133133// it helps to know how long it took for the deadline bump to be
134134// detected. The longer this takes, the more likely time drift will
@@ -148,18 +148,21 @@ func TestWorkspaceActivityBump(t *testing.T) {
148148checks ++
149149workspace ,err = client .Workspace (ctx ,workspace .ID )
150150require .NoError (t ,err )
151- updatedAfter = dbtime .Now ()
152151
153- if workspace .LatestBuild .Deadline .Time .Equal (firstDeadline ) {
154- updatedAfter = time .Now ()
155- if time .Since (lastChecked )> time .Second {
156- avgCheckTime := time .Since (waitedFor )/ time .Duration (checks )
157- t .Logf ("deadline still not updated, will continue to check: avg_check_dur=%s checks=%d deadline=%v" ,avgCheckTime ,checks ,workspace .LatestBuild .Deadline .Time )
158- lastChecked = time .Now ()
159- }
160- return false
152+ hasBumped := ! workspace .LatestBuild .Deadline .Time .Equal (firstDeadline )
153+
154+ // Always make sure to log this information, even on the last check.
155+ // The last check is the most important, as if this loop is acting
156+ // slow, the last check could be the cause of the failure.
157+ if time .Since (lastChecked )> time .Second || hasBumped {
158+ avgCheckTime := time .Since (waitedFor )/ time .Duration (checks )
159+ t .Logf ("deadline detect: bumped=%t since_last_check=%s avg_check_dur=%s checks=%d deadline=%v" ,
160+ hasBumped ,time .Since (updatedAfter ),avgCheckTime ,checks ,workspace .LatestBuild .Deadline .Time )
161+ lastChecked = time .Now ()
161162}
162- return true
163+
164+ updatedAfter = dbtime .Now ()
165+ return hasBumped
163166},
164167maxTimeDrift ,testutil .IntervalFast ,
165168"deadline %v never updated" ,firstDeadline ,