tstest: coalesce dropped Ticker ticks when advancing the clock far ahead

Clock.Advance previously fired each Ticker once per period between the
current time and the advance target, even though all but the first few
sends were dropped on the Ticker's full channel. A test that advances
the clock 180 days with a 5 second ticker registered did 3.1 million
fires, each taking a mutex, attempting a channel send, and fixing the
event heap. Under the race detector, where synchronization operations
are 20-30x more expensive, this dominated test runtime.

Now, when a tick is dropped because the channel is full, skip the
remaining missed ticks in one step, staying aligned to the original
schedule and still firing the final tick at or before the advance
target. This matches time.Ticker, which drops ticks it cannot deliver,
and is observably identical behavior. Ticks that fit in the channel are
still all delivered.

In the internal corp repo, this takes controlclient.TestExpiry under
race from 6.0s to 2.2s (its no-race time is 0.5s), and the new
benchmark improves from 449µs to 90ns per 24h advance:

  BenchmarkTickerLargeAdvance-16  100       449313 ns/op    (before)
  BenchmarkTickerLargeAdvance-16  13311910      90.22 ns/op (after)

Updates tailscale/corp#47035

Change-Id: I4826df212415eb2ea7ceb5bc46848e816f8ccde1
Signed-off-by: Brad Fitzpatrick <bradfitz@tailscale.com>

tstest/clock.go

@@ -340,8 +340,15 @@ type eventManager struct {
 	// timer triggers.
 	clock tstime.Clock
 
-	mu            sync.Mutex
-	now           time.Time
+	mu  sync.Mutex
+	now time.Time
+
+	// advanceTo is the target time of the in-progress processEventsLocked
+	// call. Event handlers fired during that call may read it (they run
+	// with mu held) to coalesce work that would otherwise repeat once per
+	// period between now and advanceTo.
+	advanceTo time.Time
+
 	heap          []*event
 	reverseLookup map[eventHandler]*event
 
@@ -468,6 +475,7 @@ func (em *eventManager) Now() time.Time {
 }
 
 func (em *eventManager) processEventsLocked(tm time.Time) {
+	em.advanceTo = tm
 	for len(em.heap) > 0 && !em.heap[0].when.After(tm) {
 		// Ideally some jitter would be added here but it's difficult to do so
 		// in a deterministic fashion.
@@ -548,11 +556,24 @@ func (t *Ticker) Fire(curTime time.Time) time.Time {
 	if t.nextTrigger.IsZero() {
 		return time.Time{}
 	}
+	sent := false
 	select {
 	case t.c <- curTime:
+		sent = true
 	default:
 	}
 	t.nextTrigger = t.nextTrigger.Add(t.period)
+	// If the channel is full and the clock is being advanced far past this
+	// ticker's next trigger, the intermediate ticks would all be dropped
+	// anyway, so skip them in one step rather than firing once per period.
+	// This keeps ticks aligned to the original schedule and still fires the
+	// final tick at or before the advance target.
+	if !sent {
+		if target := t.em.advanceTo; t.nextTrigger.Before(target) {
+			skipped := target.Sub(t.nextTrigger) / t.period
+			t.nextTrigger = t.nextTrigger.Add(skipped * t.period)
+		}
+	}
 
 	return t.nextTrigger
 }

tstest/clock_test.go

@@ -654,6 +654,32 @@ func TestSingleTicker(t *testing.T) {
 				},
 			},
 		},
+		{
+			// A large advance drops ticks that don't fit in the channel,
+			// but later ticks must stay aligned to the original schedule.
+			name:        "dropped-ticks-remain-aligned",
+			start:       time.Unix(12345, 0),
+			period:      time.Second,
+			channelSize: 1,
+			steps: []testStep{
+				{
+					advance:  5 * time.Second,
+					wantTime: time.Unix(12350, 0),
+					wantTicks: []time.Time{
+						time.Unix(12346, 0),
+						// Remaining ticks dropped due to channel size.
+					},
+				},
+				{
+					advance:  2 * time.Second,
+					wantTime: time.Unix(12352, 0),
+					wantTicks: []time.Time{
+						time.Unix(12351, 0),
+						// Second tick dropped due to channel size.
+					},
+				},
+			},
+		},
 		{
 			name:        "multiple-tick-per-step",
 			start:       time.Unix(12345, 0),
@@ -2472,3 +2498,18 @@ func TestSince(t *testing.T) {
 		})
 	}
 }
+
+// BenchmarkTickerLargeAdvance measures advancing the clock far past a
+// short-period ticker's next trigger, as happens when a test using an
+// injected clock jumps days into the future while background loops hold
+// tickers with periods of a few seconds. Most of the intermediate ticks
+// are dropped because the channel is full, so they should be cheap.
+func BenchmarkTickerLargeAdvance(b *testing.B) {
+	clock := NewClock(ClockOpts{Start: time.Unix(12345, 0)})
+	tick, _ := clock.NewTicker(5 * time.Second)
+	defer tick.Stop()
+	b.ReportAllocs()
+	for b.Loop() {
+		clock.Advance(24 * time.Hour)
+	}
+}