Merge cockroachdb#133861

133861: kvcoord: use crtime.Mono r=RaduBerinde a=RaduBerinde

#### go.mod: bump crlib to b010812ae6c8

Epic: none
Release note: None

#### kvcoord: use crtime.Mono

Replace uses of `time.Now` with `crtime.NowMono`. This also makes the
code much cleaner - we no longer need to manually convert to
`UnixNano()` and can use `crtime.AtomicMono`.

Informs: cockroachdb#133315
Release note: None

Co-authored-by: Radu Berinde <[email protected]>

DEPS.bzl

@@ -1725,10 +1725,10 @@ def go_deps():
         name = "com_github_cockroachdb_crlib",
         build_file_proto_mode = "disable_global",
         importpath = "github.com/cockroachdb/crlib",
-        sha256 = "1b5ea611b164e06a4a6c1f8f717bf7423d0636b804dcf89feaa3cd7c5e0b192e",
-        strip_prefix = "github.com/cockroachdb/[email protected]20241029192319-1184f0e87dbc",
+        sha256 = "5ab3c0365c2823d061262e8dfb951d658aba57bf8fd32f893d1345a5520ddaeb",
+        strip_prefix = "github.com/cockroachdb/[email protected]20241030165019-b010812ae6c8",
         urls = [
-            "https://storage.googleapis.com/cockroach-godeps/gomod/github.com/cockroachdb/crlib/com_github_cockroachdb_crlib-v0.0.0-20241029192319-1184f0e87dbc.zip",
+            "https://storage.googleapis.com/cockroach-godeps/gomod/github.com/cockroachdb/crlib/com_github_cockroachdb_crlib-v0.0.0-20241030165019-b010812ae6c8.zip",
         ],
     )
     go_repository(

build/bazelutil/distdir_files.bzl

@@ -337,7 +337,7 @@ DISTDIR_FILES = {
     "https://storage.googleapis.com/cockroach-godeps/gomod/github.com/cockroachdb/cmux/com_github_cockroachdb_cmux-v0.0.0-20170110192607-30d10be49292.zip": "88f6f9cf33eb535658540b46f6222f029398e590a3ff9cc873d7d561ac6debf0",
     "https://storage.googleapis.com/cockroach-godeps/gomod/github.com/cockroachdb/cockroach-go/v2/com_github_cockroachdb_cockroach_go_v2-v2.3.7.zip": "028c29c79c2d373bca3ce9a475291285fdcb68a2f908190f738d5ce605edbd07",
     "https://storage.googleapis.com/cockroach-godeps/gomod/github.com/cockroachdb/crlfmt/com_github_cockroachdb_crlfmt-v0.0.0-20221214225007-b2fc5c302548.zip": "fedc01bdd6d964da0425d5eaac8efadc951e78e13f102292cc0774197f09ab63",
-    "https://storage.googleapis.com/cockroach-godeps/gomod/github.com/cockroachdb/crlib/com_github_cockroachdb_crlib-v0.0.0-20241029192319-1184f0e87dbc.zip": "1b5ea611b164e06a4a6c1f8f717bf7423d0636b804dcf89feaa3cd7c5e0b192e",
+    "https://storage.googleapis.com/cockroach-godeps/gomod/github.com/cockroachdb/crlib/com_github_cockroachdb_crlib-v0.0.0-20241030165019-b010812ae6c8.zip": "5ab3c0365c2823d061262e8dfb951d658aba57bf8fd32f893d1345a5520ddaeb",
     "https://storage.googleapis.com/cockroach-godeps/gomod/github.com/cockroachdb/datadriven/com_github_cockroachdb_datadriven-v1.0.3-0.20240530155848-7682d40af056.zip": "f4cb70fec2b2904a56bfbda6a6c8bf9ea1d568a5994ecdb825f770671119b63b",
     "https://storage.googleapis.com/cockroach-godeps/gomod/github.com/cockroachdb/errors/com_github_cockroachdb_errors-v1.11.3.zip": "d11ed59d96afef2d1f0ce56892839c62ff5c0cbca8dff0aaefeaef7eb190e73c",
     "https://storage.googleapis.com/cockroach-godeps/gomod/github.com/cockroachdb/fifo/com_github_cockroachdb_fifo-v0.0.0-20240606204812-0bbfbd93a7ce.zip": "41e682b393cc82891ab5fcefbd28cc6173f16887702ab8760bcbc66d122e5900",

go.mod

@@ -128,7 +128,7 @@ require (
 	github.com/cockroachdb/cmux v0.0.0-20170110192607-30d10be49292
 	github.com/cockroachdb/cockroach-go/v2 v2.3.7
 	github.com/cockroachdb/crlfmt v0.0.0-20221214225007-b2fc5c302548
-	github.com/cockroachdb/crlib v0.0.0-20241029192319-1184f0e87dbc
+	github.com/cockroachdb/crlib v0.0.0-20241030165019-b010812ae6c8
 	github.com/cockroachdb/datadriven v1.0.3-0.20240530155848-7682d40af056
 	github.com/cockroachdb/errors v1.11.3
 	github.com/cockroachdb/fifo v0.0.0-20240606204812-0bbfbd93a7ce

go.sum

@@ -516,8 +516,8 @@ github.com/cockroachdb/cockroach-go/v2 v2.3.7 h1:nq5GYDuA2zIR/kdLkVLTg7oHTw0UbGU
 github.com/cockroachdb/cockroach-go/v2 v2.3.7/go.mod h1:1wNJ45eSXW9AnOc3skntW9ZUZz6gxrQK3cOj3rK+BC8=
 github.com/cockroachdb/crlfmt v0.0.0-20221214225007-b2fc5c302548 h1:i0bnjanlWAvM50wHMT7EFyxlt5HQusznWrkwl+HBIsU=
 github.com/cockroachdb/crlfmt v0.0.0-20221214225007-b2fc5c302548/go.mod h1:qtkxNlt5i3rrdirfJE/bQeW/IeLajKexErv7jEIV+Uc=
-github.com/cockroachdb/crlib v0.0.0-20241029192319-1184f0e87dbc h1:c2saheFLOrGIGAFpm1nHrmOgbIZCy4w8VI0Veh4zE64=
-github.com/cockroachdb/crlib v0.0.0-20241029192319-1184f0e87dbc/go.mod h1:Gq51ZeKaFCXk6QwuGM0w1dnaOqc/F5zKT2zA9D6Xeac=
+github.com/cockroachdb/crlib v0.0.0-20241030165019-b010812ae6c8 h1:Ew/6WPoxfQ3CMMVt2beepDpoeRRH+m9CHh8O7+GQhhg=
+github.com/cockroachdb/crlib v0.0.0-20241030165019-b010812ae6c8/go.mod h1:Gq51ZeKaFCXk6QwuGM0w1dnaOqc/F5zKT2zA9D6Xeac=
 github.com/cockroachdb/datadriven v0.0.0-20190809214429-80d97fb3cbaa/go.mod h1:zn76sxSg3SzpJ0PPJaLDCu+Bu0Lg3sKTORVIj19EIF8=
 github.com/cockroachdb/datadriven v1.0.2/go.mod h1:a9RdTaap04u637JoCzcUoIcDmvwSUtcUFtT/C3kJlTU=
 github.com/cockroachdb/datadriven v1.0.3-0.20240530155848-7682d40af056 h1:slXychO2uDM6hYRu4c0pD0udNI8uObfeKN6UInWViS8=

pkg/kv/kvclient/kvcoord/BUILD.bazel

@@ -88,6 +88,7 @@ go_library(
         "//pkg/util/timeutil",
         "//pkg/util/tracing",
         "//pkg/util/uuid",
+        "@com_github_cockroachdb_crlib//crtime",
         "@com_github_cockroachdb_errors//:errors",
         "@com_github_cockroachdb_errors//errorspb",
         "@com_github_cockroachdb_logtags//:logtags",
@@ -231,6 +232,7 @@ go_test(
         "//pkg/util/tracing",
         "//pkg/util/tracing/tracingpb",
         "//pkg/util/uuid",
+        "@com_github_cockroachdb_crlib//crtime",
         "@com_github_cockroachdb_datadriven//:datadriven",
         "@com_github_cockroachdb_errors//:errors",
         "@com_github_cockroachdb_errors//errutil",

pkg/kv/kvclient/kvcoord/dist_sender.go

@@ -41,6 +41,7 @@ import (
 	"github.com/cockroachdb/cockroach/pkg/util/syncutil"
 	"github.com/cockroachdb/cockroach/pkg/util/timeutil"
 	"github.com/cockroachdb/cockroach/pkg/util/tracing"
+	"github.com/cockroachdb/crlib/crtime"
 	"github.com/cockroachdb/errors"
 	"github.com/cockroachdb/redact"
 )
@@ -1365,7 +1366,7 @@ func (ds *DistSender) sendProxyRequest(
 	// never evaluated locally.
 	sendCtx, cbToken, cbErr := ds.circuitBreakers.
 		ForReplica(&ba.ProxyRangeInfo.Desc, &ba.ProxyRangeInfo.Lease.Replica).
-		Track(ctx, ba, withCommit, timeutil.Now().UnixNano())
+		Track(ctx, ba, withCommit, crtime.NowMono())
 	if cbErr != nil {
 		ds.metrics.ProxyForwardErrCount.Inc(1)
 		// Circuit breaker is tripped. Return immediately.
@@ -1380,7 +1381,7 @@ func (ds *DistSender) sendProxyRequest(
 
 	// If the request failed because the circuit breaker tripped, change our
 	// error to the circuit breaker's error.
-	if cancelErr := cbToken.Done(br, err, timeutil.Now().UnixNano()); cancelErr != nil {
+	if cancelErr := cbToken.Done(br, err, crtime.NowMono()); cancelErr != nil {
 		log.VEventf(ctx, 2, "failing proxy request after cb cancellation %s", err)
 		br, err = nil, cancelErr
 	}
@@ -2718,17 +2719,16 @@ func (ds *DistSender) sendToReplicas(
 			ds.metrics.ProxySentCount.Inc(1)
 		}
 
-		tBegin := timeutil.Now() // for slow log message
-		sendCtx, cbToken, cbErr := ds.circuitBreakers.ForReplica(desc, &curReplica).
-			Track(ctx, ba, withCommit, tBegin.UnixNano())
+		tBegin := crtime.NowMono() // for slow log message
+		sendCtx, cbToken, cbErr := ds.circuitBreakers.ForReplica(desc, &curReplica).Track(ctx, ba, withCommit, tBegin)
 		if cbErr != nil {
 			// Circuit breaker is tripped. err will be handled below.
 			err = cbErr
 			transport.SkipReplica()
 		} else {
 			br, err = transport.SendNext(sendCtx, requestToSend)
-			tEnd := timeutil.Now()
-			if cancelErr := cbToken.Done(br, err, tEnd.UnixNano()); cancelErr != nil {
+			tEnd := crtime.NowMono()
+			if cancelErr := cbToken.Done(br, err, tEnd); cancelErr != nil {
 				// The request was cancelled by the circuit breaker tripping. If this is
 				// detected by request evaluation (as opposed to the transport send), it
 				// will return the context error in br.Error instead of err, which won't

pkg/kv/kvclient/kvcoord/dist_sender_circuit_breaker.go

@@ -22,6 +22,7 @@ import (
 	"github.com/cockroachdb/cockroach/pkg/util/stop"
 	"github.com/cockroachdb/cockroach/pkg/util/syncutil"
 	"github.com/cockroachdb/cockroach/pkg/util/timeutil"
+	"github.com/cockroachdb/crlib/crtime"
 	"github.com/cockroachdb/errors"
 	"github.com/cockroachdb/redact"
 )
@@ -302,13 +303,13 @@ func (d *DistSenderCircuitBreakers) probeStallLoop(ctx context.Context) {
 
 		// Probe replicas for a stall if we haven't seen a response from them in the
 		// past probe threshold.
-		nowNanos := timeutil.Now().UnixNano()
+		now := crtime.NowMono()
 		probeThreshold := CircuitBreakerProbeThreshold.Get(&d.settings.SV)
 
 		d.replicas.Range(func(_ cbKey, cb *ReplicaCircuitBreaker) bool {
 			// Don't probe if the breaker is already tripped. It will be probed in
 			// response to user traffic, to reduce the number of concurrent probes.
-			if cb.stallDuration(nowNanos) >= probeThreshold && !cb.isTripped() {
+			if cb.stallDuration(now) >= probeThreshold && !cb.isTripped() {
 				cb.breaker.Probe()
 			}
 
@@ -339,13 +340,13 @@ func (d *DistSenderCircuitBreakers) gcLoop(ctx context.Context) {
 			return
 		}
 
-		nowNanos := timeutil.Now().UnixNano()
+		now := crtime.NowMono()
 
 		var cbs, gced int
 		d.replicas.Range(func(key cbKey, cb *ReplicaCircuitBreaker) bool {
 			cbs++
 
-			if idleDuration := cb.lastRequestDuration(nowNanos); idleDuration >= cbGCThreshold {
+			if idleDuration := cb.lastRequestDuration(now); idleDuration >= cbGCThreshold {
 				// Check if we raced with a concurrent delete or replace. We don't
 				// expect to, since only this loop removes circuit breakers.
 				if cb2, ok := d.replicas.LoadAndDelete(key); ok {
@@ -438,22 +439,21 @@ type ReplicaCircuitBreaker struct {
 	// inflightReqs tracks the number of in-flight requests.
 	inflightReqs atomic.Int32
 
-	// lastRequest contains the last request timestamp (in nanoseconds), for
-	// garbage collection.
-	lastRequest atomic.Int64
+	// lastRequest contains the last request timestamp, for garbage collection.
+	lastRequest crtime.AtomicMono
 
-	// errorSince is the timestamp (in nanoseconds) when the current streak of
-	// errors began. Set on an initial error, and cleared on successful responses.
-	errorSince atomic.Int64
+	// errorSince is the timestamp when the current streak of errors began. Set on
+	// an initial error, and cleared on successful responses.
+	errorSince crtime.AtomicMono
 
-	// stallSince is the timestamp (in nanoseconds) when the current potential
-	// stall began. It is set on every first in-flight request (inflightReqs==1)
-	// and moved forward on every response from the replica (even errors).
+	// stallSince is the timestamp when the current potential stall began. It is
+	// set on every first in-flight request (inflightReqs==1) and moved forward on
+	// every response from the replica (even errors).
 	//
 	// It is not reset to zero when inflightReqs==0, to avoid synchronization with
 	// inflightReqs. To determine whether a replica is stalled, it is therefore
 	// also necessary to check inflightReqs>0.
-	stallSince atomic.Int64
+	stallSince crtime.AtomicMono
 
 	// closedC is closed when the circuit breaker has been GCed. This will shut
 	// down a running probe, and prevent new probes from launching.
@@ -524,9 +524,9 @@ type replicaCircuitBreakerToken struct {
 // cancelled by the circuit breaker, an appropriate context cancellation error
 // is returned.
 func (t replicaCircuitBreakerToken) Done(
-	br *kvpb.BatchResponse, sendErr error, nowNanos int64,
+	br *kvpb.BatchResponse, sendErr error, now crtime.Mono,
 ) error {
-	return t.r.done(t.ctx, t.cancelCtx, t.ba, t.withCommit, br, sendErr, nowNanos)
+	return t.r.done(t.ctx, t.cancelCtx, t.ba, t.withCommit, br, sendErr, now)
 }
 
 // id returns a string identifier for the replica.
@@ -535,32 +535,32 @@ func (r *ReplicaCircuitBreaker) id() redact.RedactableString {
 		r.rangeID, r.desc.ReplicaID, r.desc.NodeID, r.desc.StoreID)
 }
 
-// errorDuration returns the error duration relative to nowNanos.
-func (r *ReplicaCircuitBreaker) errorDuration(nowNanos int64) time.Duration {
+// errorDuration returns the error duration relative to now.
+func (r *ReplicaCircuitBreaker) errorDuration(now crtime.Mono) time.Duration {
 	errorSince := r.errorSince.Load()
-	if errorSince == 0 || errorSince > nowNanos {
+	if errorSince == 0 || errorSince > now {
 		return 0
 	}
-	return time.Duration(nowNanos - errorSince)
+	return now.Sub(errorSince)
 }
 
-// stallDuration returns the stall duration relative to nowNanos.
-func (r *ReplicaCircuitBreaker) stallDuration(nowNanos int64) time.Duration {
+// stallDuration returns the stall duration relative to now.
+func (r *ReplicaCircuitBreaker) stallDuration(now crtime.Mono) time.Duration {
 	stallSince := r.stallSince.Load()
 	// The replica is only stalled if there are in-flight requests.
-	if r.inflightReqs.Load() == 0 || stallSince > nowNanos {
+	if r.inflightReqs.Load() == 0 || stallSince > now {
 		return 0
 	}
-	return time.Duration(nowNanos - stallSince)
+	return now.Sub(stallSince)
 }
 
-// lastRequestDuration returns the last request duration relative to nowNanos.
-func (r *ReplicaCircuitBreaker) lastRequestDuration(nowNanos int64) time.Duration {
+// lastRequestDuration returns the last request duration relative to now.
+func (r *ReplicaCircuitBreaker) lastRequestDuration(now crtime.Mono) time.Duration {
 	lastRequest := r.lastRequest.Load()
-	if lastRequest == 0 || lastRequest > nowNanos {
+	if lastRequest == 0 || lastRequest > now {
 		return 0
 	}
-	return time.Duration(nowNanos - lastRequest)
+	return now.Sub(lastRequest)
 }
 
 // Err returns the circuit breaker error if it is tripped.
@@ -603,14 +603,14 @@ func (r *ReplicaCircuitBreaker) isClosed() bool {
 // for the send and a token which the caller must call Done() on with the result
 // of the request.
 func (r *ReplicaCircuitBreaker) Track(
-	ctx context.Context, ba *kvpb.BatchRequest, withCommit bool, nowNanos int64,
+	ctx context.Context, ba *kvpb.BatchRequest, withCommit bool, now crtime.Mono,
 ) (context.Context, replicaCircuitBreakerToken, error) {
 	if r == nil {
 		return ctx, replicaCircuitBreakerToken{}, nil // circuit breakers disabled
 	}
 
 	// Record the request timestamp.
-	r.lastRequest.Store(nowNanos)
+	r.lastRequest.Store(now)
 
 	// Check if the breaker is tripped. If it is, this will also launch a probe if
 	// one isn't already running.
@@ -632,7 +632,7 @@ func (r *ReplicaCircuitBreaker) Track(
 	// Record in-flight requests. If this is the only request, tentatively start
 	// tracking a stall.
 	if inflightReqs := r.inflightReqs.Add(1); inflightReqs == 1 {
-		r.stallSince.Store(nowNanos)
+		r.stallSince.Store(now)
 	} else if inflightReqs < 0 {
 		log.Fatalf(ctx, "inflightReqs %d < 0", inflightReqs) // overflow
 	}
@@ -644,30 +644,26 @@ func (r *ReplicaCircuitBreaker) Track(
 	// also allocates. Ideally, it should be possible to propagate cancellation of
 	// a single replica-scoped context onto all request contexts, but this
 	// requires messing with Go internals.
-	sendCtx := ctx
 	if CircuitBreakerCancellation.Get(&r.d.settings.SV) {
 		// If the request already has a timeout that is below the probe threshold
 		// and probe timeout, there is no point in us cancelling it (only relevant
 		// with replica stalls). This is the common case when using statement
 		// timeouts, and avoids the overhead.
-		deadline, hasTimeout := ctx.Deadline()
-		hasTimeout = hasTimeout && deadline.UnixNano() < nowNanos+
-			CircuitBreakerProbeThreshold.Get(&r.d.settings.SV).Nanoseconds()+
-			CircuitBreakerProbeTimeout.Get(&r.d.settings.SV).Nanoseconds()
-
-		if !hasTimeout {
-			var cancel context.CancelCauseFunc
-			sendCtx, cancel = context.WithCancelCause(ctx)
+		if deadline, hasTimeout := ctx.Deadline(); !hasTimeout ||
+			crtime.MonoFromTime(deadline).Sub(now) >
+				CircuitBreakerProbeThreshold.Get(&r.d.settings.SV)+CircuitBreakerProbeTimeout.Get(&r.d.settings.SV) {
+			sendCtx, cancel := context.WithCancelCause(ctx)
 			token.cancelCtx = sendCtx
 
 			reqKind := cbRequestCancellationPolicyFromBatch(ba, withCommit)
 			r.mu.Lock()
 			r.mu.cancelFns[reqKind][ba] = cancel
 			r.mu.Unlock()
+			return sendCtx, token, nil
 		}
 	}
 
-	return sendCtx, token, nil
+	return ctx, token, nil
 }
 
 // done records the result of a tracked request and untracks it. It is called
@@ -682,7 +678,7 @@ func (r *ReplicaCircuitBreaker) done(
 	withCommit bool,
 	br *kvpb.BatchResponse,
 	sendErr error,
-	nowNanos int64,
+	now crtime.Mono,
 ) error {
 	if r == nil {
 		return nil // circuit breakers disabled when we began tracking the request
@@ -738,7 +734,7 @@ func (r *ReplicaCircuitBreaker) done(
 	// NB: we don't reset this to 0 when inflightReqs==0 to avoid unnecessary
 	// synchronization.
 	if sendErr == nil {
-		r.stallSince.Store(nowNanos)
+		r.stallSince.Store(now)
 	}
 
 	// Record error responses, by setting err non-nil. Otherwise, the response is
@@ -778,10 +774,10 @@ func (r *ReplicaCircuitBreaker) done(
 	if err == nil {
 		// On success, reset the error tracking.
 		r.errorSince.Store(0)
-	} else if errorDuration := r.errorDuration(nowNanos); errorDuration == 0 {
+	} else if errorDuration := r.errorDuration(now); errorDuration == 0 {
 		// If this is the first error we've seen, record it. We'll launch a probe on
 		// a later error if necessary.
-		r.errorSince.Store(nowNanos)
+		r.errorSince.Store(now)
 	} else if errorDuration >= CircuitBreakerProbeThreshold.Get(&r.d.settings.SV) {
 		// The replica has been failing for the past probe threshold, probe it.
 		r.breaker.Probe()
@@ -888,7 +884,7 @@ func (r *ReplicaCircuitBreaker) launchProbe(report func(error), done func()) {
 			report(err)
 			if err == nil {
 				// On a successful probe, record the success and stop probing.
-				r.stallSince.Store(timeutil.Now().UnixNano())
+				r.stallSince.Store(crtime.NowMono())
 				r.errorSince.Store(0)
 				return
 			}
@@ -944,7 +940,7 @@ func (r *ReplicaCircuitBreaker) launchProbe(report func(error), done func()) {
 			// NB: we check this after waiting out the probe interval above, to avoid
 			// frequently spawning new probe goroutines, instead waiting to see if any
 			// requests come in.
-			if r.lastRequestDuration(timeutil.Now().UnixNano()) >= cbProbeIdleTimeout {
+			if r.lastRequestDuration(crtime.NowMono()) >= cbProbeIdleTimeout {
 				// Keep probing if the write grace timer hasn't expired yet, since we
 				// need to cancel pending writes first.
 				if writeGraceTimer.C == nil {
@@ -1052,9 +1048,9 @@ func (r *ReplicaCircuitBreaker) OnTrip(b *circuit.Breaker, prev, cur error) {
 		// TODO(erikgrinaker): consider rate limiting these with log.Every, but for
 		// now we want to know which ones trip for debugging.
 		ctx := r.d.ambientCtx.AnnotateCtx(context.Background())
-		nowNanos := timeutil.Now().UnixNano()
-		stallSince := r.stallDuration(nowNanos).Truncate(time.Millisecond)
-		errorSince := r.errorDuration(nowNanos).Truncate(time.Millisecond)
+		now := crtime.NowMono()
+		stallSince := r.stallDuration(now).Truncate(time.Millisecond)
+		errorSince := r.errorDuration(now).Truncate(time.Millisecond)
 		log.Errorf(ctx, "%s circuit breaker tripped: %s (stalled for %s, erroring for %s)",
 			r.id(), cur, stallSince, errorSince)
 
@@ -1102,9 +1098,9 @@ func (r *ReplicaCircuitBreaker) OnProbeLaunched(b *circuit.Breaker) {
 	}
 
 	ctx := r.d.ambientCtx.AnnotateCtx(context.Background())
-	nowNanos := timeutil.Now().UnixNano()
-	stallSince := r.stallDuration(nowNanos).Truncate(time.Millisecond)
-	errorSince := r.errorDuration(nowNanos).Truncate(time.Millisecond)
+	now := crtime.NowMono()
+	stallSince := r.stallDuration(now).Truncate(time.Millisecond)
+	errorSince := r.errorDuration(now).Truncate(time.Millisecond)
 	tripped := r.breaker.Signal().IsTripped()
 	log.VEventf(ctx, 2, "launching circuit breaker probe for %s (tripped=%t stall=%s error=%s)",
 		r.id(), tripped, stallSince, errorSince)
@@ -1131,9 +1127,9 @@ func (r *ReplicaCircuitBreaker) OnProbeDone(b *circuit.Breaker) {
 	}
 
 	ctx := r.d.ambientCtx.AnnotateCtx(context.Background())
-	nowNanos := timeutil.Now().UnixNano()
+	now := crtime.NowMono()
 	tripped := r.breaker.Signal().IsTripped()
-	lastRequest := r.lastRequestDuration(nowNanos).Truncate(time.Millisecond)
+	lastRequest := r.lastRequestDuration(now).Truncate(time.Millisecond)
 	log.VEventf(ctx, 2, "stopping circuit breaker probe for %s (tripped=%t lastRequest=%s)",
 		r.id(), tripped, lastRequest)
 }