CodeRigor
Course home

LESSON

Define the telemetry contract and inject a clock

Measure whole elapsed milliseconds with a replaceable clock and distinguish a measured zero from invalid timing.

Instrumentation starts with a contract: which requests are counted, what a duration means, which fields are allowed in a log, and which labels can form metric series.

This course extends the working notes API and observability foundations. The outcome is actual instrumentation plus a reproduced local incident, not another disconnected log-analysis fixture. Hosted work uses recorders; the download also runs an owned loopback service.

Timing is one dependency in the request path
start / 3
Two readings from an injected clock surround the handler. Validation determines whether a real duration sample exists.
Timing is one dependency in the request path
Two readings from an injected clock surround the handler. Validation determines whether a real duration sample exists.

Use time.Time.Sub instead of subtracting formatted wall-clock strings. Real time.Now readings can carry a monotonic component; deterministic tests supply known time values. An injected clock does not turn fixture durations into a benchmark.

The result is whole milliseconds. A 999-microsecond interval is a valid zero at this resolution. A reversed clock is an error, even though the function’s numeric result is also zero.

Go 
package main
import ("fmt";"time")
func main(){
start:=time.Unix(0,0);for _,d:=range []time.Duration{0,999*time.Microsecond,12*time.Millisecond}{fmt.Println(start.Add(d).Sub(start).Milliseconds())}
}

The caller keeps duration as an optional value. On an invalid clock reading it still counts the request, emits an event with duration_ms null and skips that histogram sample. That preserves a useful denominator distinction: requests observed is not always timings observed.

A metric name carries its unit. A millisecond histogram must not receive nanoseconds, and a displayed average must describe its actual sample population. The fixed lab histogram later reports a bucket upper bound for p95, not an exact percentile.

The local service uses time.Now. The replay uses deterministic prescribed readings through the same middleware, so its logs/counters are actual emitted artifacts while its durations are explicitly synthetic.

Missing timing does not erase the request
start / 3
Counters record the attempt. Only valid timing enters the latency distribution, and the event makes absence visible.
Missing timing does not erase the request
Counters record the attempt. Only valid timing enters the latency distribution, and the event makes absence visible.
Go 
package main
import ("fmt";"encoding/json")
func main(){
type event struct{Duration *int64 `json:"duration_ms"`};unknown,_:=json.Marshal(event{});zero:=int64(0);measured,_:=json.Marshal(event{&zero});fmt.Println(string(unknown),string(measured))
}

Complete the conversion and test equal, sub-millisecond, cross-second and reversed readings. Keep tests deterministic without sleeps.

Next we attach a server-owned request ID to context and the response so one exchange can be followed across emitted evidence.

Watch & read

Free lectures, talks and readings that cover this skill from another angle. All resources →

Optional primary discussion of structured logging and Go’s slog design. This lab uses a small explicit event DTO; the continuation expands into logger configuration, storage and a fuller observability stack.