Compare commits

...

1 Commits

Author SHA1 Message Date
Claire Wang
4e81dba5a9 *: use tstime
Updates #8587

Signed-off-by: Claire Wang <claire@tailscale.com>
2023-07-21 15:28:20 -04:00
25 changed files with 120 additions and 58 deletions

View File

@@ -11,6 +11,8 @@ import (
"net"
"strings"
"time"
"tailscale.com/tstime"
)
const (
@@ -18,6 +20,8 @@ const (
responseTimeout = 10 * time.Second
)
var clock = tstime.StdClock{}
// New creates a BIRDClient.
func New(socket string) (*BIRDClient, error) {
return newWithTimeout(socket, responseTimeout)
@@ -38,7 +42,7 @@ func newWithTimeout(socket string, timeout time.Duration) (_ *BIRDClient, err er
socket: socket,
conn: conn,
scanner: bufio.NewScanner(conn),
timeNow: time.Now,
timeNow: clock.Now,
timeout: timeout,
}
// Read and discard the first line as that is the welcome message.

View File

@@ -17,6 +17,7 @@ import (
"tailscale.com/envknob"
"tailscale.com/tailcfg"
"tailscale.com/tstime"
"tailscale.com/util/multierr"
"tailscale.com/util/set"
)
@@ -28,7 +29,7 @@ var (
sysErr = map[Subsystem]error{} // error key => err (or nil for no error)
watchers = set.HandleSet[func(Subsystem, error)]{} // opt func to run if error state changes
warnables = map[*Warnable]struct{}{} // set of warnables
timer *time.Timer
timer tstime.TimerController
debugHandler = map[string]http.Handler{}
@@ -49,6 +50,7 @@ var (
lastLoginErr error
localLogConfigErr error
tlsConnectionErrors = map[string]error{} // map[ServerName]error
clock = tstime.StdClock{}
)
// Subsystem is the name of a subsystem whose health can be monitored.
@@ -162,7 +164,7 @@ func RegisterWatcher(cb func(key Subsystem, err error)) (unregister func()) {
defer mu.Unlock()
handle := watchers.Add(cb)
if timer == nil {
timer = time.AfterFunc(time.Minute, timerSelfCheck)
timer = clock.AfterFunc(time.Minute, timerSelfCheck)
}
return func() {
mu.Lock()
@@ -282,7 +284,7 @@ func SetControlHealth(problems []string) {
func GotStreamedMapResponse() {
mu.Lock()
defer mu.Unlock()
lastStreamedMapResponse = time.Now()
lastStreamedMapResponse = clock.Now()
selfCheckLocked()
}
@@ -296,9 +298,9 @@ func SetInPollNetMap(v bool) {
}
inMapPoll = v
if v {
inMapPollSince = time.Now()
inMapPollSince = clock.Now()
} else {
lastMapPollEndedAt = time.Now()
lastMapPollEndedAt = clock.Now()
}
}
@@ -327,7 +329,7 @@ func NoteMapRequestHeard(mr *tailcfg.MapRequest) {
// against SetMagicSockDERPHome and
// SetDERPRegionConnectedState
lastMapRequestHeard = time.Now()
lastMapRequestHeard = clock.Now()
selfCheckLocked()
}
@@ -354,7 +356,7 @@ func SetDERPRegionHealth(region int, problem string) {
func NoteDERPRegionReceivedFrame(region int) {
mu.Lock()
defer mu.Unlock()
derpRegionLastFrame[region] = time.Now()
derpRegionLastFrame[region] = clock.Now()
selfCheckLocked()
}
@@ -435,7 +437,7 @@ func overallErrorLocked() error {
if lastLoginErr != nil {
return fmt.Errorf("not logged in, last login error=%v", lastLoginErr)
}
now := time.Now()
now := clock.Now()
if !inMapPoll && (lastMapPollEndedAt.IsZero() || now.Sub(lastMapPollEndedAt) > 10*time.Second) {
return errors.New("not in map poll")
}

View File

@@ -21,6 +21,7 @@ import (
"go4.org/mem"
"tailscale.com/envknob"
"tailscale.com/tailcfg"
"tailscale.com/tstime"
"tailscale.com/types/opt"
"tailscale.com/types/ptr"
"tailscale.com/util/cloudenv"
@@ -29,7 +30,8 @@ import (
"tailscale.com/version"
)
var started = time.Now()
var clock = tstime.StdClock{}
var started = clock.Now()
// New returns a partially populated Hostinfo for the current host.
func New() *tailcfg.Hostinfo {
@@ -221,7 +223,7 @@ func desktop() (ret opt.Bool) {
ret.Set(seenDesktop)
// Only cache after a minute - compositors might not have started yet.
if time.Since(started) > time.Minute {
if clock.Since(started) > time.Minute {
desktopAtomic.Store(ret)
}
return ret

View File

@@ -23,6 +23,7 @@ import (
"sync"
"time"
"tailscale.com/tstime"
"tailscale.com/util/multierr"
)
@@ -35,6 +36,8 @@ const (
// service account directory.
var rootPathForTests string
var clock = tstime.StdClock{}
// SetRootPathForTesting sets the path to the service account directory.
func SetRootPathForTesting(p string) {
rootPathForTests = p
@@ -100,14 +103,14 @@ func (c *Client) SetDialer(dialer func(ctx context.Context, network, addr string
func (c *Client) expireToken() {
c.mu.Lock()
defer c.mu.Unlock()
c.tokenExpiry = time.Now()
c.tokenExpiry = clock.Now()
}
func (c *Client) getOrRenewToken() (string, error) {
c.mu.Lock()
defer c.mu.Unlock()
tk, te := c.token, c.tokenExpiry
if time.Now().Before(te) {
if clock.Now().Before(te) {
return tk, nil
}
@@ -116,7 +119,7 @@ func (c *Client) getOrRenewToken() (string, error) {
return "", err
}
c.token = string(tkb)
c.tokenExpiry = time.Now().Add(30 * time.Minute)
c.tokenExpiry = clock.Now().Add(30 * time.Minute)
return c.token, nil
}

View File

@@ -16,6 +16,7 @@ import (
"sync"
"time"
"tailscale.com/tstime"
"tailscale.com/types/logger"
)
@@ -24,6 +25,8 @@ const (
maxFiles = 50
)
var clock = tstime.StdClock{}
// New returns a logf wrapper that appends to local disk log
// files on Windows, rotating old log files as needed to stay under
// file count & byte limits.
@@ -99,7 +102,7 @@ func (w *logFileWriter) Logf(format string, a ...any) {
// out should end in a newline.
// w.mu must be held.
func (w *logFileWriter) appendToFileLocked(out []byte) {
now := time.Now()
now := clock.Now()
day := dayOf(now)
if w.fday != day {
w.startNewFileLocked()
@@ -155,7 +158,7 @@ func (w *logFileWriter) startNewFileLocked() {
}
w.cleanLocked()
now := time.Now()
now := clock.Now()
day := dayOf(now)
name := filepath.Join(w.dir, fmt.Sprintf("%s-%04d%02d%02dT%02d%02d%02d-%d.txt",
w.fileBasePrefix,

View File

@@ -23,6 +23,7 @@ import (
"tailscale.com/net/netmon"
"tailscale.com/net/sockstats"
"tailscale.com/smallzstd"
"tailscale.com/tstime"
"tailscale.com/types/logger"
"tailscale.com/types/logid"
"tailscale.com/util/mak"
@@ -81,6 +82,8 @@ type event struct {
Stats map[sockstats.Label]deltaStat `json:"s"`
}
var clock = tstime.StdClock{}
// SockstatLogID reproducibly derives a new logid.PrivateID for sockstat logging from a node's public backend log ID.
// The returned PrivateID is the sha256 sum of logID + "sockstat".
// If a node's public log ID becomes known, it is trivial to spoof sockstat logs for that node.
@@ -175,13 +178,13 @@ func (l *Logger) poll() {
var lastStats *sockstats.SockStats
var lastTime time.Time
ticker := time.NewTicker(pollInterval)
ticker, tickerChannel := clock.NewTicker(pollInterval)
for {
select {
case <-l.ctx.Done():
ticker.Stop()
return
case t := <-ticker.C:
case t := <-tickerChannel:
stats := sockstats.Get()
if lastStats != nil {
diffstats := delta(lastStats, stats)
@@ -219,13 +222,13 @@ func (l *Logger) logEvents() {
}
}
}
ticker := time.NewTicker(logInterval)
ticker, tickerChannel := clock.NewTicker(logInterval)
for {
select {
case <-l.ctx.Done():
ticker.Stop()
return
case <-ticker.C:
case <-tickerChannel:
flush()
}
}

View File

@@ -44,6 +44,7 @@ import (
"tailscale.com/paths"
"tailscale.com/safesocket"
"tailscale.com/smallzstd"
"tailscale.com/tstime"
"tailscale.com/types/logger"
"tailscale.com/types/logid"
"tailscale.com/util/clientmetric"
@@ -658,6 +659,8 @@ func NewWithConfigPath(collection, dir, cmdName string, netMon *netmon.Monitor,
// in the happy path, thus generating more logs.
var dialLog = log.New(io.Discard, "logtail: ", log.LstdFlags|log.Lmsgprefix)
var clock = tstime.StdClock{}
// SetVerbosityLevel controls the verbosity level that should be
// written to stderr. 0 is the default (not verbose). Levels 1 or higher
// are increasingly verbose.
@@ -706,9 +709,9 @@ func dialContext(ctx context.Context, netw, addr string, netMon *netmon.Monitor,
Timeout: 30 * time.Second,
KeepAlive: netknob.PlatformTCPKeepAlive(),
})
t0 := time.Now()
t0 := clock.Now()
c, err := nd.DialContext(ctx, netw, addr)
d := time.Since(t0).Round(time.Millisecond)
d := clock.Since(t0).Round(time.Millisecond)
if err == nil {
dialLog.Printf("dialed %q in %v", addr, d)
return c, nil

View File

@@ -12,12 +12,14 @@ import (
"os"
"path/filepath"
"strings"
"time"
"github.com/peterbourgon/ff/v3/ffcli"
"tailscale.com/release/dist"
"tailscale.com/tstime"
)
var clock = tstime.StdClock{}
// CLI returns a CLI root command to build release packages.
//
// getTargets is a function that gets run in the Exec function of commands that
@@ -101,7 +103,7 @@ func runBuild(ctx context.Context, filters []string, targets []dist.Target) erro
return errors.New("no targets matched (did you mean 'dist build all'?)")
}
st := time.Now()
st := clock.Now()
wd, err := os.Getwd()
if err != nil {
return fmt.Errorf("getting working directory: %w", err)
@@ -139,6 +141,6 @@ func runBuild(ctx context.Context, filters []string, targets []dist.Target) erro
}
}
fmt.Println("Done! Took", time.Since(st))
fmt.Println("Done! Took", clock.Since(st))
return nil
}

View File

@@ -19,6 +19,7 @@ import (
"sync"
"time"
"tailscale.com/tstime"
"tailscale.com/util/multierr"
"tailscale.com/version/mkversion"
)
@@ -66,6 +67,8 @@ type Build struct {
goBuildLimit chan struct{}
}
var clock = tstime.StdClock{}
// NewBuild creates a new Build rooted at repo, and writing artifacts to out.
func NewBuild(repo, out string) (*Build, error) {
if err := os.MkdirAll(out, 0750); err != nil {
@@ -89,7 +92,7 @@ func NewBuild(repo, out string) (*Build, error) {
Out: out,
Go: goTool,
Version: mkversion.Info(),
Time: time.Now().UTC(),
Time: clock.Now().UTC(),
extra: map[any]any{},
goBuildLimit: make(chan struct{}, runtime.NumCPU()),
}

View File

@@ -10,6 +10,8 @@ import (
"net"
"runtime"
"time"
"tailscale.com/tstime"
)
type closeable interface {
@@ -29,14 +31,15 @@ func ConnCloseWrite(c net.Conn) error {
return c.(closeable).CloseWrite()
}
var processStartTime = time.Now()
var clock = tstime.StdClock{}
var processStartTime = clock.Now()
var tailscaledProcExists = func() bool { return false } // set by safesocket_ps.go
// tailscaledStillStarting reports whether tailscaled is probably
// still starting up. That is, it reports whether the caller should
// keep retrying to connect.
func tailscaledStillStarting() bool {
d := time.Since(processStartTime)
d := clock.Since(processStartTime)
if d < 2*time.Second {
// Without even checking the process table, assume
// that for the first two seconds that tailscaled is

View File

@@ -39,6 +39,7 @@ import (
"tailscale.com/net/tsdial"
"tailscale.com/tailcfg"
"tailscale.com/tempfork/gliderlabs/ssh"
"tailscale.com/tstime"
"tailscale.com/types/key"
"tailscale.com/types/logger"
"tailscale.com/types/netmap"
@@ -76,9 +77,8 @@ type server struct {
logf logger.Logf
tailscaledPath string
pubKeyHTTPClient *http.Client // or nil for http.DefaultClient
timeNow func() time.Time // or nil for time.Now
pubKeyHTTPClient *http.Client // or nil for http.DefaultClient
clock tstime.Clock
sessionWaitGroup sync.WaitGroup
// mu protects the following
@@ -88,11 +88,13 @@ type server struct {
shutdownCalled bool
}
var clock = tstime.StdClock{}
func (srv *server) now() time.Time {
if srv != nil && srv.timeNow != nil {
return srv.timeNow()
if srv != nil && srv.clock != nil {
return srv.clock.Now()
}
return time.Now()
return clock.Now()
}
func init() {
@@ -1615,7 +1617,7 @@ func (ss *sshSession) startNewRecording() (_ *recording, err error) {
term = "xterm-256color" // something non-empty
}
now := time.Now()
now := clock.Now()
rec := &recording{
ss: ss,
start: now,
@@ -1827,7 +1829,7 @@ type loggingWriter struct {
func (w *loggingWriter) Write(p []byte) (n int, err error) {
if !w.recordingFailedOpen {
j, err := json.Marshal([]any{
time.Since(w.r.start).Seconds(),
clock.Since(w.r.start).Seconds(),
w.dir,
string(p),
})

View File

@@ -1015,7 +1015,7 @@ func TestPublicKeyFetching(t *testing.T) {
clock := &tstest.Clock{}
srv := &server{
pubKeyHTTPClient: ts.Client(),
timeNow: clock.Now,
clock: clock,
}
for i := 0; i < 2; i++ {
got, err := srv.fetchPublicKeysURL(keys + "/alice.keys")

View File

@@ -7,8 +7,12 @@ import (
"context"
"sync"
"time"
"tailscale.com/tstime"
)
var clock = tstime.StdClock{}
// Watch monitors mu for contention.
// On first call, and at every tick, Watch locks and unlocks mu.
// (Tick should be large to avoid adding contention to mu.)
@@ -49,10 +53,10 @@ func Watch(ctx context.Context, mu sync.Locker, tick, max time.Duration) chan ti
var sendonce sync.Once
done := make(chan bool)
go func() {
start := time.Now()
start := clock.Now()
mu.Lock()
mu.Unlock()
elapsed := time.Since(start)
elapsed := clock.Since(start)
if elapsed > max {
elapsed = max
}

View File

@@ -4,6 +4,8 @@ import (
"context"
"net"
"time"
"tailscale.com/tstime"
)
type serverConn struct {
@@ -14,6 +16,8 @@ type serverConn struct {
closeCanceler context.CancelFunc
}
var clock = tstime.StdClock{}
func (c *serverConn) Write(p []byte) (n int, err error) {
c.updateDeadline()
n, err = c.Conn.Write(p)
@@ -43,7 +47,7 @@ func (c *serverConn) Close() (err error) {
func (c *serverConn) updateDeadline() {
switch {
case c.idleTimeout > 0:
idleDeadline := time.Now().Add(c.idleTimeout)
idleDeadline := clock.Now().Add(c.idleTimeout)
if idleDeadline.Unix() < c.maxDeadline.Unix() || c.maxDeadline.IsZero() {
c.Conn.SetDeadline(idleDeadline)
return

View File

@@ -285,7 +285,7 @@ func (srv *Server) HandleConn(newConn net.Conn) {
closeCanceler: cancel,
}
if srv.MaxTimeout > 0 {
conn.maxDeadline = time.Now().Add(srv.MaxTimeout)
conn.maxDeadline = clock.Now().Add(srv.MaxTimeout)
}
defer conn.Close()
sshConn, chans, reqs, err := gossh.NewServerConn(conn, srv.config(ctx))

View File

@@ -49,6 +49,7 @@ import (
"tailscale.com/net/tsdial"
"tailscale.com/smallzstd"
"tailscale.com/tsd"
"tailscale.com/tstime"
"tailscale.com/types/logger"
"tailscale.com/types/logid"
"tailscale.com/types/nettype"
@@ -59,6 +60,8 @@ import (
func inTest() bool { return flag.Lookup("test.v") != nil }
var clock = tstime.StdClock{}
// Server is an embedded Tailscale server.
//
// Its exported fields may be changed until the first method call.
@@ -1096,11 +1099,11 @@ func (ln *listener) closeLocked() error {
}
func (ln *listener) handle(c net.Conn) {
t := time.NewTimer(time.Second)
t, tChannel := clock.NewTimer(time.Second)
defer t.Stop()
select {
case ln.conn <- c:
case <-t.C:
case <-tChannel:
// TODO(bradfitz): this isn't ideal. Think about how
// we how we want to do pushback.
c.Close()

View File

@@ -50,7 +50,7 @@ type AccessLogRecord struct {
// String returns m as a JSON string.
func (m AccessLogRecord) String() string {
if m.When.IsZero() {
m.When = time.Now()
m.When = clock.Now()
}
var buf strings.Builder
json.NewEncoder(&buf).Encode(m)

View File

@@ -25,6 +25,7 @@ import (
"go4.org/mem"
"tailscale.com/envknob"
"tailscale.com/net/tsaddr"
"tailscale.com/tstime"
"tailscale.com/tsweb/varz"
"tailscale.com/types/logger"
"tailscale.com/util/cmpx"
@@ -34,6 +35,8 @@ import (
// DevMode controls whether extra output in shown, for when the binary is being run in dev mode.
var DevMode bool
var clock = tstime.StdClock{}
func DefaultCertDir(leafDir string) string {
cacheDir, err := os.UserCacheDir()
if err == nil {
@@ -169,7 +172,7 @@ type ReturnHandler interface {
type HandlerOptions struct {
QuietLoggingIfSuccessful bool // if set, do not log successfully handled HTTP requests (200 and 304 status codes)
Logf logger.Logf
Now func() time.Time // if nil, defaults to time.Now
Now func() time.Time // if nil, defaults to tstime.Clock.Now
// If non-nil, StatusCodeCounters maintains counters
// of status codes for handled responses.
@@ -205,7 +208,7 @@ func (f ReturnHandlerFunc) ServeHTTPReturn(w http.ResponseWriter, r *http.Reques
// Errors are handled as specified by the Handler interface.
func StdHandler(h ReturnHandler, opts HandlerOptions) http.Handler {
if opts.Now == nil {
opts.Now = time.Now
opts.Now = clock.Now
}
if opts.Logf == nil {
opts.Logf = logger.Discard

View File

@@ -18,6 +18,7 @@ import (
"time"
"tailscale.com/metrics"
"tailscale.com/tstime"
"tailscale.com/util/cmpx"
"tailscale.com/version"
)
@@ -39,9 +40,11 @@ const (
// prefixesToTrim contains key prefixes to remove when exporting and sorting metrics.
var prefixesToTrim = []string{gaugePrefix, counterPrefix, labelMapPrefix}
var timeStart = time.Now()
var clock = tstime.StdClock{}
func Uptime() time.Duration { return time.Since(timeStart).Round(time.Second) }
var timeStart = clock.Now()
func Uptime() time.Duration { return clock.Since(timeStart).Round(time.Second) }
// WritePrometheusExpvar writes kv to w in Prometheus metrics format.
//

View File

@@ -21,6 +21,7 @@ import (
"context"
"tailscale.com/envknob"
"tailscale.com/tstime"
)
// Logf is the basic Tailscale logger type: a printf-like func.
@@ -47,6 +48,8 @@ var jencPool = &sync.Pool{New: func() any {
return je
}}
var clock = tstime.StdClock{}
// JSON marshals v as JSON and writes it to logf formatted with the annotation to make logtail
// treat it as a structured log.
//
@@ -144,7 +147,7 @@ var rateFree = []string{
// RateLimitedFn is a wrapper for RateLimitedFnWithClock that includes the
// current time automatically. This is mainly for backward compatibility.
func RateLimitedFn(logf Logf, f time.Duration, burst int, maxCache int) Logf {
return RateLimitedFnWithClock(logf, f, burst, maxCache, time.Now)
return RateLimitedFnWithClock(logf, f, burst, maxCache, clock.Now)
}
// RateLimitedFnWithClock returns a rate-limiting Logf wrapping the given
@@ -259,10 +262,10 @@ func SlowLoggerWithClock(ctx context.Context, logf Logf, f time.Duration, burst
// Otherwise, sleep for 2x the duration so that we don't
// immediately sleep again on the next call.
tmr := time.NewTimer(2 * f)
tmr, tmrChannel := clock.NewTimer(2 * f)
defer tmr.Stop()
select {
case curr := <-tmr.C:
case curr := <-tmrChannel:
tb.AdvanceTo(curr)
case <-ctx.Done():
return

View File

@@ -15,6 +15,7 @@ import (
qt "github.com/frankban/quicktest"
"tailscale.com/tailcfg"
"tailscale.com/tstime"
)
func TestFuncWriter(t *testing.T) {
@@ -98,7 +99,8 @@ func TestRateLimiter(t *testing.T) {
}
func testTimer(d time.Duration) func() time.Time {
timeNow := time.Now()
testClock := tstime.StdClock{}
timeNow := testClock.Now()
return func() time.Time {
timeNow = timeNow.Add(d)
return timeNow

View File

@@ -16,6 +16,8 @@ import (
"sync"
"sync/atomic"
"time"
"tailscale.com/tstime"
)
var (
@@ -76,6 +78,8 @@ type Metric struct {
lastNamed time.Time
}
var clock = tstime.StdClock{}
func (m *Metric) Name() string { return m.name }
func (m *Metric) Value() int64 {
@@ -271,7 +275,7 @@ func EncodeLogTailMetricsDelta() string {
mu.Lock()
defer mu.Unlock()
now := time.Now()
now := clock.Now()
if !lastDelta.IsZero() && now.Sub(lastDelta) < minMetricEncodeInterval {
return ""
}

View File

@@ -25,8 +25,8 @@ import (
"encoding/hex"
"reflect"
"sync"
"time"
"tailscale.com/tstime"
"tailscale.com/util/hashx"
)
@@ -124,8 +124,10 @@ var (
seed uint64
)
var clock = tstime.StdClock{}
func initSeed() {
seed = uint64(time.Now().UnixNano())
seed = uint64(clock.Now().UnixNano())
}
// Hash returns the hash of v.

View File

@@ -7,19 +7,21 @@ import (
"fmt"
"os"
"strings"
"time"
"github.com/google/uuid"
"golang.org/x/sys/unix"
"tailscale.com/tstime"
)
var clock = tstime.StdClock{}
func setQuarantineAttr(f *os.File) error {
sc, err := f.SyscallConn()
if err != nil {
return err
}
now := time.Now()
now := clock.Now()
// We uppercase the UUID to match what other applications on macOS do
id := strings.ToUpper(uuid.New().String())

View File

@@ -438,6 +438,8 @@ const (
// ErrKeyWaitTimeout is returned by OpenKeyWait when calls timeout.
var ErrKeyWaitTimeout = errors.New("timeout waiting for registry key")
var clock = tstime.StdClock{}
// OpenKeyWait opens a registry key, waiting for it to appear if necessary. It
// returns the opened key, or ErrKeyWaitTimeout if the key does not appear
// within 20s. The caller must call Close on the returned key.
@@ -445,7 +447,7 @@ func OpenKeyWait(k registry.Key, path RegistryPath, access uint32) (registry.Key
runtime.LockOSThread()
defer runtime.UnlockOSThread()
deadline := time.Now().Add(keyOpenTimeout)
deadline := clock.Now().Add(keyOpenTimeout)
pathSpl := strings.Split(string(path), "\\")
for i := 0; ; i++ {
keyName := pathSpl[i]