Skip to main content
RunBook Academy

ObservabilityXXXI · Logging FoundationsLoggingFoundations

Timestamps and Time Zones

Foundation⏱ ~16 minbashchronyclogclidate

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

Not yet marked complete on this device.

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:00 or 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.

  1. 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.
  2. 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.
  3. 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.

  1. Local-time logs. time.Now().Format("2006-01-02 15:04:05") without time.UTC or a timezone suffix. Loki parses the line as UTC. The real time is Europe/London and 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.
  2. Missing offset. A line with "2026-01-15 03:12:44.512" and no Z. 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.
  3. 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.
  4. 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.
  5. 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).
  6. 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”:

  1. What does the raw line say? tail -F /var/log/app/checkout.log and inspect the ts field. If it is missing the offset, the bug is in the application.
  2. 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 the timestamp stage is misconfigured.
  3. Is the host clock honest? chronyc tracking and look at the System time line. If the skew is large, no amount of pipeline configuration will help.
  4. Is the timestamp format documented? Check the application’s logging config. The fix for “missing offset” is the format string, not the pipeline.
  5. Is the same offset in use everywhere? Compare two services side by side: logcli query '\{job="app"\} | json | __error__=""' --since=5m and logcli 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. chronyd against an internal stratum one (or pool.ntp.org if no internal source exists). Verify chronyc tracking weekly.
  • 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

  1. Q1. Which format is the right one for a production log timestamp?

  2. Q2. Where should the timestamp be generated?

  3. Q3. A timestamp without a timezone suffix is unambiguous because modern parsers default to UTC.

  4. Q4. Which of these are real production failure modes of a misconfigured timestamp pipeline?

  5. Q5. Name the two timestamps Loki has for every log line.

  6. Q6. A high-volume service generates several events per millisecond. Which precision is the right choice?

  7. Q7. The Loki pipeline timestamp stage falls back to ingest time when the structured field is missing or unparseable.

  8. Q8. Which command confirms the host clock is synchronised to NTP?

Passing score: 75%. Answers are checked in this browser.