Skip to content

ADR 0083: A historian row is stamped with the observation

Status: Accepted Date: 2026-08-24 Issue: #1812 Related: ADR 0027 (what a tag timestamp means, and where the historian is named as ignoring it), ADR 0081 (the queue whose repair made the replay reachable)

Context

Every historian ingest path stamped time.Now(), the instant the historian happened to receive the message. That number equals the observation only while delivery is prompt. The product has two paths where delivery is not prompt.

The first is the store-and-forward queue. A unit runtime holds one on its own disk and drains it on the next connect, so a promoted runtime replays whatever its own last stint left behind. This was measured on the bench on 2026-08-24 while verifying #1797. The runtime came up under binding epoch 37, announced a queue of 8,781 messages, and drained it over about a hundred seconds. The record for that minute now carries two operating states at once:

Address 22:29:44 to 22:30:40 23:30 to 23:31, control
loop-pid.SP 478 rows at 0, 324 rows at 60 300 rows, all 0
loop-pid.CV 473 rows at 0, 322 rows at 100 300 rows, all 0
aux-output.CMD 637 rows at 0, 167 rows at 50 300 rows, all 0

The unit was Idle with no batch running. The second state belongs to the drill-11 reps of 20:09 to 20:33 that day. The insert rate says the same thing without reference to any value. The historian took 72 rows a second before the promotion, 183 for the minute of it, and 72 again from 22:31 onward. That is about 7,400 rows more than the steady rate accounts for, against a queue that announced 8,781.

The second path is retention on the wire. The alarm and CM-health topics are published retained, so the broker hands the standing message to every new subscriber. Each historian restart therefore re-ingested every alarm still standing in the plant and dated each one at the restart. Read back, that says the whole annunciator re-fired at 03:14.

The mechanism was one field. mqtt.Message carried a Timestamp from the first commit. Subscribe never set it and nothing else in the tree did either, so it was the zero time on every message ever delivered. Four ingest paths read it, found it zero, and fell through to time.Now(). Only the CM-health path had anything in front of that fallback, because it reads the payload's since, and that is why it was the only one recording an event time at all.

The event time was never missing from the wire. The runtime marshals driver.TagValue as-is, whose Timestamp is the ADR 0027 observation time and whose own doc comment says it is what "any historian record depend[s] on". The alarm and state publishers stamp the payload's timestamp. A control module's health carries since. What was missing was a reader.

Two consequences make this worth doing now. A failover replays by construction, in the first seconds after the promotion. That is the same minute every failover drill measures, so the contamination is not random with respect to the question being asked. It lands on the answer. And the trend an operator opens after an incident is this table. A 21 CFR Part 11 record showing a 60 % setpoint on a unit that was Idle is worse than a gap, because a gap is visibly a gap.

#1780 is what made the first path reachable. Before it, a queue held behind one refused message never drained at all for the life of the pod, and a backlog that never replays never rewrites anything. The fix that made the queue drain correctly is what put the old readings into the record.

Decision

A historian row is stamped with the instant the observation was made, taken off the payload the publisher wrote. Arrival time is the fallback, and it is counted.

Ingester.stampAt in pkg/historian/eventtime.go is the one place the decision is taken. All four paths call it, so a fifth cannot quietly differ.

The event time is read by the consumer, and the transport stamps nothing. mqtt.Message.Timestamp is deleted. MQTT carries no transport timestamp, so the only thing pkg/mqtt could stamp is receive time. That is the number the consumers already have, wearing a name that claims to be the observation, and filling the field would turn every IsZero() fallback into dead code and make the defect permanent. The event time is on the payload, whose schema belongs to the publisher. It is therefore read where the schema is known.

A future timestamp is refused, and an old one never is. A declared instant more than 30 seconds ahead of the historian's own clock is a clock fault, and the row takes arrival time. There is no bound in the other direction. An old timestamp is the case this change exists to serve, and a replayed backlog is old by construction.

The asymmetry is not symmetry for its own sake. A future-dated row is worse than wrong on the trend. Migration 001 records that a chunk cannot be dropped by drop_chunks() while its range_end is still in the future. A row dated past the retention horizon therefore pins a chunk the prune CronJob can never reclaim, and the historian PVC fills. Thirty seconds is comfortably above anything a synchronised host leaves behind, since chrony steps at one second and does not slew past it, and it is far below the one-hour chunk interval. A clock fault is therefore refused long before it can reach a chunk nothing will drop.

The fallback is visible. dcs_historian_ingest_time_fallback_total{type, reason} counts every row that had to take arrival time. The three reasons name three different faults with three different remedies: absent for an old publisher, unparseable for a broken one, future for a clock. Every combination of the two labels is created at zero, so a silent fallback reads as silent and not as an absent series. One log line per interval carries the account of its window. It is rate-limited because a publisher that stops carrying a timestamp does so on every message, and on the tag topic that is the plant's full sample rate.

The state and alarm publishers carry sub-second precision. They stamped whole-second RFC 3339. Reading that off the wire would have coarsened rows that arrival time was recording at nanosecond precision. A phase completing and the next one starting routinely share a second. There is no sequence column, so those two rows would tie. The batch record's own ordering would then become whatever the query happened to return. RFC3339Nano output is valid RFC 3339, so the published contract is unchanged. The parser accepts both formats, so a historian reading an older publisher still gets its second.

Alternatives Considered

Stamp receive time into mqtt.Message.Timestamp. The one-line reading of "the field has no writer, so give it one". Rejected. It is the number the consumers already compute, so it changes nothing. It also turns every IsZero() fallback into unreachable code, which leaves the defect in place with the last sign of it removed. That is the shape ADR 0077 is about.

Leave the field and fix only the historian. Rejected. Two other consumers read it and fall back the same way, and a field that can only ever be zero is a trap the next consumer walks into. It is deleted, and the two remaining consumers now write time.Now() where they mean it. That is the honest form of what they were already doing, and the real fix is tracked as #1817.

Refuse a record with no usable timestamp. Rejected. The historian is the only store the record is going to reach, so a dropped row is a hole where an approximately-right row would have been. The fallback stays and is counted.

Bound how old a declared timestamp may be. Rejected. That bound would refuse exactly the replay this ADR exists to honour. A very old row is dropped by retention in the ordinary way, and a compressed chunk is seven days back while a queue drain is minutes to hours.

Leave the state path on arrival time. Neither state publisher queues and the topic is not retained, so arrival is within milliseconds of the transition. Rejected. That path agrees by accident, and the rule is what survives the next topic to gain a queue or a retained flag. Half the paths reading the wire and half not is the shape that rots.

Consequences

  • Rows arrive late and out of order, and that is now correct. TimescaleDB takes them. Readers have to know it.
  • A data gap changes meaning. It stops meaning "an interval during which nothing was delivered" and starts meaning "an interval for which no observation exists". That is the honest definition and the one a Part 11 trend needs. A drill measuring a gap can now watch it shrink as a backlog drains, so when the query runs is part of what it measures. See the follow-ups.
  • dcs_historian_ingest_lag_seconds becomes true. Its published contract said "from sample timestamp to insert completion" and it could not have measured that, because the sample timestamp was the arrival. It was buffer dwell wearing the name of ingest lag, and it never left the first few buckets. It is now the instrument that makes a replay visible. Its range is extended from 12 exponential buckets, about 102 seconds, to 18, about 1.8 hours. A two-minute backlog can then be told from a two-hour one. At the old range both landed in +Inf together.
  • A re-delivered retained message lands on the instant it already occupies. There is no unique constraint on any of the three hypertables and never was, so duplicate rows were already reachable. A duplicate at the true time reads as the duplicate it is, and a reader can collapse it. A phantom at restart time reads as a fresh event, and nothing can.
  • A skewed node is visible. Its rows take arrival time and its clock is named on a counter, which is the remedy.

Follow-ups

  • The gateway TagBus and the OMF egress still stamp arrival time: settled by #1817 and ADR 0084. Both read the payload now, through a pkg/eventtime that holds the rules this ADR established so they are not written three times. The gateway is a live control surface and not a record, so it carried a question the historian did not have to answer. What should the HMI do with a value that is honestly forty minutes old? It holds the newest observation of each subject and dims it, which ADR 0084 records.
  • Drill 10's data-gap instrument reads this table for this window: drills/hist-gap.py in cndcs-deploy-bench, whose whole point (#1794) is that the data gap and the control gap are separate numbers from separate instruments. Before this change a replay dropped rows into the hole the drill was measuring, carrying values from another run. After it, a backlog whose observations fall inside the hole legitimately fills part of it, so the measured gap depends on whether the query ran before or after the drain. The instrument should say which. dcs_runtime_mqtt_queue_depth is what answers it.

References