From a17c45fd6e89a64102796aa2f4015bbf91145b96 Mon Sep 17 00:00:00 2001 From: Claire Wang Date: Fri, 4 Aug 2023 19:29:44 -0400 Subject: [PATCH] control: use tstime instead of time (#8595) Updates #8587 Signed-off-by: Claire Wang --- cmd/tailscale/depaware.txt | 2 +- control/controlclient/auto.go | 17 ++++---- control/controlclient/direct.go | 53 +++++++++++++------------ control/controlclient/map.go | 2 +- control/controlclient/map_test.go | 5 +-- control/controlclient/noise.go | 2 + control/controlclient/sign_supported.go | 2 +- control/controlhttp/client.go | 13 ++++-- control/controlhttp/constants.go | 5 +++ control/controlhttp/http_test.go | 3 ++ 10 files changed, 61 insertions(+), 43 deletions(-) diff --git a/cmd/tailscale/depaware.txt b/cmd/tailscale/depaware.txt index 920342fcc..ccf6ef811 100644 --- a/cmd/tailscale/depaware.txt +++ b/cmd/tailscale/depaware.txt @@ -110,7 +110,7 @@ tailscale.com/cmd/tailscale dependencies: (generated by github.com/tailscale/dep tailscale.com/tailcfg from tailscale.com/cmd/tailscale/cli+ tailscale.com/tka from tailscale.com/client/tailscale+ W tailscale.com/tsconst from tailscale.com/net/interfaces - tailscale.com/tstime from tailscale.com/derp+ + tailscale.com/tstime from tailscale.com/control/controlhttp+ 💣 tailscale.com/tstime/mono from tailscale.com/tstime/rate tailscale.com/tstime/rate from tailscale.com/wgengine/filter+ tailscale.com/types/dnstype from tailscale.com/tailcfg diff --git a/control/controlclient/auto.go b/control/controlclient/auto.go index a27e9e2fa..622f233af 100644 --- a/control/controlclient/auto.go +++ b/control/controlclient/auto.go @@ -15,6 +15,7 @@ import ( "tailscale.com/logtail/backoff" "tailscale.com/net/sockstats" "tailscale.com/tailcfg" + "tailscale.com/tstime" "tailscale.com/types/empty" "tailscale.com/types/key" "tailscale.com/types/logger" @@ -48,7 +49,7 @@ var _ Client = (*Auto)(nil) // It's a concrete implementation of the Client interface. type Auto struct { direct *Direct // our interface to the server APIs - timeNow func() time.Time + clock tstime.Clock logf logger.Logf expiry *time.Time closed bool @@ -107,12 +108,12 @@ func NewNoStart(opts Options) (_ *Auto, err error) { if opts.Logf == nil { opts.Logf = func(fmt string, args ...any) {} } - if opts.TimeNow == nil { - opts.TimeNow = time.Now + if opts.Clock == nil { + opts.Clock = tstime.StdClock{} } c := &Auto{ direct: direct, - timeNow: opts.TimeNow, + clock: opts.Clock, logf: opts.Logf, newMapCh: make(chan struct{}, 1), quit: make(chan struct{}), @@ -208,7 +209,7 @@ func (c *Auto) sendNewMapRequest() { c.liteMapUpdateCancel = cancel go func() { defer cancel() - t0 := time.Now() + t0 := c.clock.Now() err := c.direct.SendLiteMapUpdate(ctx) d := time.Since(t0).Round(time.Millisecond) @@ -704,14 +705,14 @@ func (c *Auto) Logout(ctx context.Context) error { c.mu.Unlock() c.cancelAuth() - timer := time.NewTimer(10 * time.Second) + timer, timerChannel := c.clock.NewTimer(10 * time.Second) defer timer.Stop() select { case err := <-errc: return err case <-ctx.Done(): return ctx.Err() - case <-timer.C: + case <-timerChannel: return context.DeadlineExceeded } } @@ -772,7 +773,7 @@ func (c *Auto) TestOnlySetAuthKey(authkey string) { } func (c *Auto) TestOnlyTimeNow() time.Time { - return c.timeNow() + return c.clock.Now() } // SetDNS sends the SetDNSRequest request to the control plane server, diff --git a/control/controlclient/direct.go b/control/controlclient/direct.go index ffc0467f7..28b3c97a6 100644 --- a/control/controlclient/direct.go +++ b/control/controlclient/direct.go @@ -45,6 +45,7 @@ import ( "tailscale.com/syncs" "tailscale.com/tailcfg" "tailscale.com/tka" + "tailscale.com/tstime" "tailscale.com/types/key" "tailscale.com/types/logger" "tailscale.com/types/netmap" @@ -63,7 +64,7 @@ type Direct struct { dialer *tsdial.Dialer dnsCache *dnscache.Resolver serverURL string // URL of the tailcontrol server - timeNow func() time.Time + clock tstime.Clock lastPrintMap time.Time newDecompressor func() (Decompressor, error) keepAlive bool @@ -105,8 +106,8 @@ type Options struct { GetMachinePrivateKey func() (key.MachinePrivate, error) // returns the machine key to use ServerURL string // URL of the tailcontrol server AuthKey string // optional node auth key for auto registration - TimeNow func() time.Time // time.Now implementation used by Client - Hostinfo *tailcfg.Hostinfo // non-nil passes ownership, nil means to use default using os.Hostname, etc + Clock tstime.Clock + Hostinfo *tailcfg.Hostinfo // non-nil passes ownership, nil means to use default using os.Hostname, etc DiscoPublicKey key.DiscoPublic NewDecompressor func() (Decompressor, error) KeepAlive bool @@ -191,8 +192,8 @@ func NewDirect(opts Options) (*Direct, error) { if err != nil { return nil, err } - if opts.TimeNow == nil { - opts.TimeNow = time.Now + if opts.Clock == nil { + opts.Clock = tstime.StdClock{} } if opts.Logf == nil { // TODO(apenwarr): remove this default and fail instead. @@ -235,7 +236,7 @@ func NewDirect(opts Options) (*Direct, error) { httpc: httpc, getMachinePrivKey: opts.GetMachinePrivateKey, serverURL: opts.ServerURL, - timeNow: opts.TimeNow, + clock: opts.Clock, logf: opts.Logf, newDecompressor: opts.NewDecompressor, keepAlive: opts.KeepAlive, @@ -432,7 +433,7 @@ func (c *Direct) doLogin(ctx context.Context, opt loginOpt) (mustRegen bool, new authKey, isWrapped, wrappedSig, wrappedKey := decodeWrappedAuthkey(c.authKey, c.logf) hi := c.hostInfoLocked() backendLogID := hi.BackendLogID - expired := c.expiry != nil && !c.expiry.IsZero() && c.expiry.Before(c.timeNow()) + expired := c.expiry != nil && !c.expiry.IsZero() && c.expiry.Before(c.clock.Now()) c.mu.Unlock() machinePrivKey, err := c.getMachinePrivKey() @@ -537,7 +538,7 @@ func (c *Direct) doLogin(ctx context.Context, opt loginOpt) (mustRegen bool, new err = errors.New("hostinfo: BackendLogID missing") return regen, opt.URL, nil, err } - now := time.Now().Round(time.Second) + now := c.clock.Now().Round(time.Second) request := tailcfg.RegisterRequest{ Version: 1, OldNodeKey: oldNodeKey, @@ -911,7 +912,7 @@ func (c *Direct) sendMapRequest(ctx context.Context, maxPolls int, readOnly bool defer cancel() machinePubKey := machinePrivKey.Public() - t0 := time.Now() + t0 := c.clock.Now() // Url and httpc are protocol specific. var url string @@ -954,7 +955,7 @@ func (c *Direct) sendMapRequest(ctx context.Context, maxPolls int, readOnly bool return nil } - timeout := time.NewTimer(pollTimeout) + timeout, timeoutChannel := c.clock.NewTimer(pollTimeout) timeoutReset := make(chan struct{}) pollDone := make(chan struct{}) defer close(pollDone) @@ -964,14 +965,14 @@ func (c *Direct) sendMapRequest(ctx context.Context, maxPolls int, readOnly bool case <-pollDone: vlogf("netmap: ending timeout goroutine") return - case <-timeout.C: + case <-timeoutChannel: c.logf("map response long-poll timed out!") cancel() return case <-timeoutReset: if !timeout.Stop() { select { - case <-timeout.C: + case <-timeoutChannel: case <-pollDone: vlogf("netmap: ending timeout goroutine") return @@ -1096,7 +1097,7 @@ func (c *Direct) sendMapRequest(ctx context.Context, maxPolls int, readOnly bool go dumpGoroutinesToURL(c.httpc, resp.Debug.GoroutineDumpURL) } if sleep := time.Duration(resp.Debug.SleepSeconds * float64(time.Second)); sleep > 0 { - if err := sleepAsRequested(ctx, c.logf, timeoutReset, sleep); err != nil { + if err := sleepAsRequested(ctx, c.logf, timeoutReset, sleep, c.clock); err != nil { return err } } @@ -1126,7 +1127,7 @@ func (c *Direct) sendMapRequest(ctx context.Context, maxPolls int, readOnly bool // This is handy for debugging, and our logs processing // pipeline depends on it. (TODO: Remove this dependency.) // Code elsewhere prints netmap diffs every time they are received. - now := c.timeNow() + now := c.clock.Now() if now.Sub(c.lastPrintMap) >= 5*time.Minute { c.lastPrintMap = now c.logf("[v1] new network map[%d]:\n%s", i, nm.VeryConcise()) @@ -1304,7 +1305,7 @@ func initDevKnob() devKnobs { } } -var clockNow = time.Now +var clock tstime.Clock = tstime.StdClock{} // opt.Bool configs from control. var ( @@ -1408,9 +1409,9 @@ func answerHeadPing(logf logger.Logf, c *http.Client, pr *tailcfg.PingRequest) { if pr.Log { logf("answerHeadPing: sending HEAD ping to %v ...", pr.URL) } - t0 := time.Now() + t0 := clock.Now() _, err = c.Do(req) - d := time.Since(t0).Round(time.Millisecond) + d := clock.Since(t0).Round(time.Millisecond) if err != nil { logf("answerHeadPing error: %v to %v (after %v)", err, pr.URL, d) } else if pr.Log { @@ -1456,7 +1457,7 @@ func answerC2NPing(logf logger.Logf, c2nHandler http.Handler, c *http.Client, pr if pr.Log { logf("answerC2NPing: sending POST ping to %v ...", pr.URL) } - t0 := time.Now() + t0 := clock.Now() _, err = c.Do(req) d := time.Since(t0).Round(time.Millisecond) if err != nil { @@ -1466,7 +1467,7 @@ func answerC2NPing(logf logger.Logf, c2nHandler http.Handler, c *http.Client, pr } } -func sleepAsRequested(ctx context.Context, logf logger.Logf, timeoutReset chan<- struct{}, d time.Duration) error { +func sleepAsRequested(ctx context.Context, logf logger.Logf, timeoutReset chan<- struct{}, d time.Duration, clock tstime.Clock) error { const maxSleep = 5 * time.Minute if d > maxSleep { logf("sleeping for %v, capped from server-requested %v ...", maxSleep, d) @@ -1475,20 +1476,20 @@ func sleepAsRequested(ctx context.Context, logf logger.Logf, timeoutReset chan<- logf("sleeping for server-requested %v ...", d) } - ticker := time.NewTicker(pollTimeout / 2) + ticker, tickerChannel := clock.NewTicker(pollTimeout / 2) defer ticker.Stop() - timer := time.NewTimer(d) + timer, timerChannel := clock.NewTimer(d) defer timer.Stop() for { select { case <-ctx.Done(): return ctx.Err() - case <-timer.C: + case <-timerChannel: return nil - case <-ticker.C: + case <-tickerChannel: select { case timeoutReset <- struct{}{}: - case <-timer.C: + case <-timerChannel: return nil case <-ctx.Done(): return ctx.Err() @@ -1665,7 +1666,7 @@ func doPingerPing(logf logger.Logf, c *http.Client, pr *tailcfg.PingRequest, pin logf("invalid ping request: missing url, ip or pinger") return } - start := time.Now() + start := clock.Now() ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) defer cancel() @@ -1703,7 +1704,7 @@ func postPingResult(start time.Time, logf logger.Logf, c *http.Client, pr *tailc if pr.Log { logf("postPingResult: sending ping results to %v ...", pr.URL) } - t0 := time.Now() + t0 := clock.Now() _, err = c.Do(req) d := time.Since(t0).Round(time.Millisecond) if err != nil { diff --git a/control/controlclient/map.go b/control/controlclient/map.go index 9dcdc1c2d..714c57149 100644 --- a/control/controlclient/map.go +++ b/control/controlclient/map.go @@ -307,7 +307,7 @@ func undeltaPeers(mapRes *tailcfg.MapResponse, prev []*tailcfg.Node) { for _, n := range newFull { peerByID[n.ID] = n } - now := clockNow() + now := clock.Now() for nodeID, seen := range mapRes.PeerSeenChange { if n, ok := peerByID[nodeID]; ok { if seen { diff --git a/control/controlclient/map_test.go b/control/controlclient/map_test.go index 241053b40..cfd243b62 100644 --- a/control/controlclient/map_test.go +++ b/control/controlclient/map_test.go @@ -14,6 +14,7 @@ import ( "go4.org/mem" "tailscale.com/tailcfg" "tailscale.com/tstest" + "tailscale.com/tstime" "tailscale.com/types/key" "tailscale.com/types/netmap" "tailscale.com/types/opt" @@ -23,9 +24,6 @@ import ( func TestUndeltaPeers(t *testing.T) { var curTime time.Time - tstest.Replace(t, &clockNow, func() time.Time { - return curTime - }) online := func(v bool) func(*tailcfg.Node) { return func(n *tailcfg.Node) { @@ -298,6 +296,7 @@ func TestUndeltaPeers(t *testing.T) { t.Run(tt.name, func(t *testing.T) { if !tt.curTime.IsZero() { curTime = tt.curTime + tstest.Replace(t, &clock, tstime.Clock(tstest.NewClock(tstest.ClockOpts{Start: curTime}))) } undeltaPeers(tt.mapRes, tt.prev) if !reflect.DeepEqual(tt.mapRes.Peers, tt.want) { diff --git a/control/controlclient/noise.go b/control/controlclient/noise.go index 4a8335133..a9dd20180 100644 --- a/control/controlclient/noise.go +++ b/control/controlclient/noise.go @@ -23,6 +23,7 @@ import ( "tailscale.com/net/netmon" "tailscale.com/net/tsdial" "tailscale.com/tailcfg" + "tailscale.com/tstime" "tailscale.com/types/key" "tailscale.com/types/logger" "tailscale.com/util/mak" @@ -450,6 +451,7 @@ func (nc *NoiseClient) dial(ctx context.Context) (*noiseConn, error) { DialPlan: dialPlan, Logf: nc.logf, NetMon: nc.netMon, + Clock: tstime.StdClock{}, }).Dial(ctx) if err != nil { return nil, err diff --git a/control/controlclient/sign_supported.go b/control/controlclient/sign_supported.go index c7525b7a7..2dc8efa1e 100644 --- a/control/controlclient/sign_supported.go +++ b/control/controlclient/sign_supported.go @@ -127,7 +127,7 @@ func findIdentity(subject string, st certstore.Store) (certstore.Identity, []*x5 return nil, nil, err } - selected, chain := selectIdentityFromSlice(subject, ids, time.Now()) + selected, chain := selectIdentityFromSlice(subject, ids, clock.Now()) for _, id := range ids { if id != selected { diff --git a/control/controlhttp/client.go b/control/controlhttp/client.go index b0d91bada..fb220fd0b 100644 --- a/control/controlhttp/client.go +++ b/control/controlhttp/client.go @@ -45,6 +45,7 @@ import ( "tailscale.com/net/tlsdial" "tailscale.com/net/tshttpproxy" "tailscale.com/tailcfg" + "tailscale.com/tstime" "tailscale.com/util/multierr" ) @@ -147,13 +148,16 @@ func (a *Dialer) dial(ctx context.Context) (*ClientConn, error) { // before we do anything. if c.DialStartDelaySec > 0 { a.logf("[v2] controlhttp: waiting %.2f seconds before dialing %q @ %v", c.DialStartDelaySec, a.Hostname, c.IP) - tmr := time.NewTimer(time.Duration(c.DialStartDelaySec * float64(time.Second))) + if a.Clock == nil { + a.Clock = tstime.StdClock{} + } + tmr, tmrChannel := a.Clock.NewTimer(time.Duration(c.DialStartDelaySec * float64(time.Second))) defer tmr.Stop() select { case <-ctx.Done(): err = ctx.Err() return - case <-tmr.C: + case <-tmrChannel: } } @@ -319,7 +323,10 @@ func (a *Dialer) dialHost(ctx context.Context, addr netip.Addr) (*ClientConn, er // In case outbound port 80 blocked or MITM'ed poorly, start a backup timer // to dial port 443 if port 80 doesn't either succeed or fail quickly. - try443Timer := time.AfterFunc(a.httpsFallbackDelay(), func() { try(u443) }) + if a.Clock == nil { + a.Clock = tstime.StdClock{} + } + try443Timer := a.Clock.AfterFunc(a.httpsFallbackDelay(), func() { try(u443) }) defer try443Timer.Stop() var err80, err443 error diff --git a/control/controlhttp/constants.go b/control/controlhttp/constants.go index b838f84c4..72161336e 100644 --- a/control/controlhttp/constants.go +++ b/control/controlhttp/constants.go @@ -11,6 +11,7 @@ import ( "tailscale.com/net/dnscache" "tailscale.com/net/netmon" "tailscale.com/tailcfg" + "tailscale.com/tstime" "tailscale.com/types/key" "tailscale.com/types/logger" ) @@ -89,6 +90,10 @@ type Dialer struct { drainFinished chan struct{} omitCertErrorLogging bool testFallbackDelay time.Duration + + // tstime.Clock is used instead of time package for methods such as time.Now. + // If not specified, will default to tstime.StdClock{}. + Clock tstime.Clock } func strDef(v1, v2 string) string { diff --git a/control/controlhttp/http_test.go b/control/controlhttp/http_test.go index 3cf790d8c..c5fcdf5c3 100644 --- a/control/controlhttp/http_test.go +++ b/control/controlhttp/http_test.go @@ -25,6 +25,7 @@ import ( "tailscale.com/net/socks5" "tailscale.com/net/tsdial" "tailscale.com/tailcfg" + "tailscale.com/tstest" "tailscale.com/types/key" "tailscale.com/types/logger" ) @@ -204,6 +205,7 @@ func testControlHTTP(t *testing.T, param httpTestParam) { Logf: t.Logf, omitCertErrorLogging: true, testFallbackDelay: 50 * time.Millisecond, + Clock: &tstest.Clock{}, } if proxy != nil { @@ -660,6 +662,7 @@ func TestDialPlan(t *testing.T) { drainFinished: drained, omitCertErrorLogging: true, testFallbackDelay: 50 * time.Millisecond, + Clock: &tstest.Clock{}, } conn, err := a.dial(ctx)