ObservabilityXXXI · Logging FoundationsLoggingFoundations
Timestamps and Time Zones
What you'll learn
- Produce RFC3339 timestamps with explicit UTC offset at the source, not at the central sink
- Choose a precision (millisecond vs nanosecond) appropriate to the workload
- Diagnose clock skew, leap-second, and time-zone misinterpretation failures from log evidence
- Configure the Loki pipeline timestamp stage to honour the source time, not the ingest time
- Explain why the central sink is the wrong place to fix a missing timestamp
Prerequisites
Verified against Prometheus 2.55.x · Alertmanager 0.28.x · node_exporter 1.8.x · blackbox_exporter 0.26.x · Grafana 11.x · Loki 3.x · Tempo current · OpenTelemetry Collector 0.110.x · Grafana Alloy current · Docker Engine 28.x · Ubuntu 24.04 LTS · Debian 12 (Bookworm) · RHEL / Rocky / AlmaLinux 9.x · 2026-08-13
Two services write logs for the same user request. Service A is
honest about its clock and stamps 2026-01-15T03:12:44.512Z. Service
B uses time.Now().Format("2006-01-02 15:04:05") without a timezone
and the local box runs Europe/London. In January the output is
2026-01-15 03:12:44, which Loki parses as UTC. The real wall-clock
time was 03:12:44 GMT. The discrepancy is one second on this
particular line. Across the same request, the two services are now
one second out of order. The cross-service timeline no longer
reconstructs.
This is the lesson: the timestamp is the only thing that lets an investigator reconstruct the order of events. A timestamp without a timezone is a guess. A timestamp generated at the sink is a lie.
What a timestamp is
A timestamp is the moment at which the event being logged happened. In production logs, that moment is recorded at the source — inside the application process, at the line of code that observed the event — and the format is RFC 3339:
2026-01-15T03:12:44.512Z
The components matter:
YYYY-MM-DD— calendar date, sortable.T— literal separator, not a space.HH:MM:SS— twenty-four hour clock..512— fractional seconds. Milliseconds (.512) is the default; microseconds and nanoseconds are options for high-volume services.Z— explicit UTC. Alternatives are+00:00or a numeric offset like+05:30. Anything explicit is fine. Anything missing is a bug.
RFC 3339 is the format. The offset is mandatory. The precision is chosen by the workload.
Why a sysadmin cares
Three operational payoffs depend on a correct timestamp.
- Cross-service timeline. A request that traverses seven services cannot be reconstructed from seven local-time logs. The only way to align the per-service stories is a single timezone — UTC — at every hop.
- Backfill and replays. A pipeline that re-emits a batch of historical logs needs to honour the original event time, not the time the replay ran. Without a parseable source timestamp, the historical data lands in the wrong time bucket.
- Anomaly detection. A rate panel that compares “the same minute yesterday” needs both sides of the comparison to be UTC. Local-time data shifts the comparison by an hour twice a year (the DST boundary).
The cost of getting it wrong is invisible until 03:00. The cost of getting it right is one configuration line per service.
How it works — the mental model
Application
event happens ---> log library reads the wall clock
wall clock source: kernel (via gettimeofday / clock_gettime)
kernel clock source: chronyd / systemd-timesyncd
|
+-- NTP ---> pool.ntp.org / a local stratum-1
formatted as RFC3339 with explicit offset (usually Z)
written to stdout as part of the JSON line
Pipeline
Promtail/Alloy reads the line
timestamp stage parses the structured field
the parsed value becomes the Loki ingest timestamp
Loki stores the line in the chunk keyed on this time
Query
Grafana asks Loki for lines between t0 and t1
Loki returns the chunks in that range
The clock the application reads is the same clock NTP manages. If NTP is broken, every timestamp in the fleet is wrong by the same amount — and the skew is correlated, which is the worst kind of skew because the cross-service timeline still looks plausible.
How to configure it
The application-side fix is one line in Go:
slog.SetDefault(slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
Level: slog.LevelInfo,
})))
// slog.NewJSONHandler emits RFC3339Nano with explicit "Z" by default.
In Python with structlog:
import structlog
structlog.configure(
processors=[
structlog.processors.TimeStamper(fmt="iso", utc=True),
structlog.processors.JSONRenderer(),
],
)
In a shell-driven logger that emits a syslog-style line:
printf '%s\n' "$(date -u +%Y-%m-%dT%H:%M:%S.%3NZ) checkout[1234]: request_id=7f4a1c msg=received"
# 2026-01-15T03:12:44.512Z checkout[1234]: request_id=7f4a1c msg=received
The NTP side, which is the precondition for any of the above to be honest:
# Verify the host clock is synchronised.
chronyc tracking
# Reference ID : C0A80101 (192.168.1.1)
# System time : 0.000000234 seconds fast of NTP time
# Last offset : +0.000012 seconds
# RMS offset : 0.000087 seconds
# Frequency : 12.345 ppm fast
# Residual freq : -0.001 ppm
# Skew : 0.012 ppm
# Root delay : 0.001234 seconds
# Root dispersion : 0.000987 seconds
# Update interval : 64.2 seconds
# Leap status : Normal
The System time line is the answer. Anything more than a few
milliseconds fast or slow is a clock-sync problem, not a logging
problem.
How to validate it
The validation ladder, in order of what to check first:
# 1. The host clock is honest.
chronyc tracking | grep "System time"
# System time : 0.000000234 seconds fast of NTP time
# 2. The application is emitting UTC, explicitly.
grep '"ts":"' /var/log/app/checkout.log | head -1
# {"ts":"2026-01-15T03:12:44.512Z",...}
# 3. The pipeline is honouring the source timestamp.
logcli query --since=1h --limit=1 '{job="application"}'
# 2026-01-15T03:12:44.512Z {} ... <-- source time, not "now"
# 4. The fallback path is unused.
logcli metrics 'loki_processing_pipeline_errors_total{reason="timestamp_parse_failure"}'
# 0 (no parse failures)
# 5. Across the fleet, all hosts agree to within milliseconds.
for h in web01 web02 web03; do
ssh "$h" 'date -u +%Y-%m-%dT%H:%M:%S.%3NZ'
done
# 2026-01-15T03:12:44.512Z
# 2026-01-15T03:12:44.514Z
# 2026-01-15T03:12:44.511Z
If two hosts disagree by more than the kernel’s NTP discipline
allows (typically under 10 ms on a healthy network), the
investigation is chronyc, not the application.
How it can fail
Six recurring failure modes.
- Local-time logs.
time.Now().Format("2006-01-02 15:04:05")withouttime.UTCor a timezone suffix. Loki parses the line as UTC. The real time isEurope/Londonand the line lands in the wrong hour. Symptom: a “03:00 deploy” appears under 04:00 in Loki; DST transitions produce two incidents per year. - Missing offset. A line with
"2026-01-15 03:12:44.512"and noZ. Loki’s timestamp parser either rejects it or guesses UTC. Symptom: the line appears under “now” if Loki falls back to ingest time; the analyst concludes the event happened during the investigation, not before it. - Wrong precision. A high-volume service emits millisecond precision. Two events in the same millisecond collide on the Loki index. Symptom: panels that count events show numbers that are stable across the entire spike — events that should have been counted are merged.
- Clock skew between hosts. Host A is 30 seconds ahead of host B because NTP is not configured. Cross-service timelines show the response arriving before the request. Symptom: every trace timeline is nonsense; engineers conclude the trace system is broken when it is actually the clocks.
- Leap second mishandling. A service that does not honour the
kernel’s leap-second flag logs
23:59:60, which Loki rejects. Symptom: a one-second window of logs is missing on the day the leap second is inserted (typically 30 June or 31 December). - Pipeline timestamp stage missing. The pipeline never parses the structured field, so Loki uses ingest time. Symptom: a batch backfill lands under “today” instead of under the actual event time, and the historical analysis is corrupted.
How to troubleshoot it
The diagnostic order for “the timeline looks wrong”:
- What does the raw line say?
tail -F /var/log/app/checkout.logand inspect thetsfield. If it is missing the offset, the bug is in the application. - Is the pipeline parsing it?
logcli query '\{job="app"\} | json | __error__=""' | head— Loki’s__error__label is set on lines that failed parsing. A non-zero count means thetimestampstage is misconfigured. - Is the host clock honest?
chronyc trackingand look at theSystem timeline. If the skew is large, no amount of pipeline configuration will help. - Is the timestamp format documented? Check the application’s logging config. The fix for “missing offset” is the format string, not the pipeline.
- Is the same offset in use everywhere? Compare two services
side by side:
logcli query '\{job="app"\} | json | __error__=""' --since=5mandlogcli query '\{job="web"\} | json | __error__=""' --since=5m. Different formats mean different bugs.
Security implications
The timestamp field carries no sensitive content. The risk is forensic: a corrupted timestamp erodes the value of the entire log trail as evidence. A regulator asking “show me what happened at 02:30” gets a different answer depending on whose clock is being trusted. The discipline is the same as for any audit-grade record: one clock, one format, one timezone, end to end.
The second-order risk is around leap seconds. A service that does
not handle 23:59:60 correctly produces a one-second gap in the
audit trail on the day the leap second is inserted. For most
fleets this is acceptable; for financial or trading systems it is
not. The fix is to use a clock library that tracks TAI and
converts to UTC at output, which handles the leap-second flag
correctly.
Performance implications
Timestamp parsing at the pipeline is cheap. RFC 3339 is one of the fastest formats to parse, and Loki’s timestamp stage is implemented in Go with a hand-rolled parser that runs in tens of nanoseconds per line. The cost is negligible compared to the JSON parse.
The cost the operator pays is at the source. A time.Now() call
on Linux is roughly 20 ns with vDSO acceleration — it does not
make a syscall and does not block. Logging libraries that capture
the timestamp once per request and pass it through the call stack
avoid even that. Precision below microseconds is a cost worth
measuring only if the service is on the hot path; for everything
else, the difference is rounding error.
Production guidance
- UTC, explicit, RFC 3339. Millisecond precision is the default. Nanosecond precision is appropriate only when the service genuinely generates more than one event per millisecond per host.
- One clock source per fleet.
chronydagainst an internal stratum one (orpool.ntp.orgif no internal source exists). Verifychronyc trackingweekly. - Pipeline timestamp stage. Always parse the structured field. The fallback to ingest time exists for emergencies, not for routine operation.
Verification
You should now be able to answer:
- Why must the timestamp carry an explicit UTC offset?
- Where should the timestamp be generated — at the source or at the sink?
- What is the difference between millisecond and nanosecond precision, and when does each matter?
- How does clock skew between hosts corrupt a cross-service timeline?
Quiz
Knowledge check · 8 questions
Q1. Which format is the right one for a production log timestamp?
Q2. Where should the timestamp be generated?
Q3. A timestamp without a timezone suffix is unambiguous because modern parsers default to UTC.
Q4. Which of these are real production failure modes of a misconfigured timestamp pipeline?
Q5. Name the two timestamps Loki has for every log line.
Q6. A high-volume service generates several events per millisecond. Which precision is the right choice?
Q7. The Loki pipeline timestamp stage falls back to ingest time when the structured field is missing or unparseable.
Q8. Which command confirms the host clock is synchronised to NTP?
Passing score: 75%. Answers are checked in this browser.