Historian: re-measure 30 s HistoryRead of unprovisioned tags #653

Closed
opened 2026-10-08 18:51:44 -04:00 by dohertj2 · 4 comments
Owner

Split from #600. HistoryRead of a historized tag that is not provisioned in the historian was observed to take ~30 s (the CallTimeout). Re-measure against the real gateway and decide whether to fail fast. Needs VPN to wonder-sql-vd03.

Split from #600. HistoryRead of a historized tag that is not provisioned in the historian was observed to take ~30 s (the CallTimeout). Re-measure against the real gateway and decide whether to fail fast. Needs VPN to wonder-sql-vd03.
Author
Owner

Attempted in batch b647: the historian gateway is reachable (127.0.0.1:5221 via the Mac tunnel; historian CAP on wonder-sql-vd03 accepts TCP), but it now enforces API keys (ApiKeys__Mode=ApiKey — the docs claiming Disabled are wrong) and no read-scoped key was available; every RPC returned Unauthenticated in ~0.04 s, so no data. Not minted (writes the gateway key store) — waiting on a historian:read key. Ready-to-run measurement script: 5 runs each of ReadRaw/ReadAggregate/ReadAtTime/GetTagMetadata for SysTimeSec vs a nonexistent tag. Decision rule: nonexistent-tag reads < 1 s ⇒ close as stale + fix the docs line; Raw ≈ 30 s while GetTagMetadata is fast ⇒ metadata pre-check + short negative cache in GatewayHistorianDataSource.

Attempted in batch b647: the historian gateway is reachable (127.0.0.1:5221 via the Mac tunnel; historian CAP on wonder-sql-vd03 accepts TCP), but it now enforces API keys (`ApiKeys__Mode=ApiKey` — the docs claiming Disabled are wrong) and no read-scoped key was available; every RPC returned Unauthenticated in ~0.04 s, so no data. Not minted (writes the gateway key store) — waiting on a `historian:read` key. Ready-to-run measurement script: 5 runs each of ReadRaw/ReadAggregate/ReadAtTime/GetTagMetadata for SysTimeSec vs a nonexistent tag. Decision rule: nonexistent-tag reads < 1 s ⇒ close as stale + fix the docs line; Raw ≈ 30 s while GetTagMetadata is fast ⇒ metadata pre-check + short negative cache in GatewayHistorianDataSource.
Author
Owner

Live remeasurement completed with a newly commissioned temporary historian:read key (two-hour expiry; revoked after the run). Five sequential calls per operation through client 0.3.0 and the running local gateway/upstream AVEVA connection:

Operation SysTimeSec range Nonexistent tag range
Metadata 48–299 ms, success 41–89 ms, gateway exception
Raw 99–159 ms, success 30.260–30.754 s, gateway exception
Aggregate 249–309 ms, success 30.564–30.806 s, gateway exception
AtTime 88–140 ms, success 61.074–61.601 s, gateway exception

Tag: OtOpcUa.Issue653.Nonexistent.20261013. No historian writes/provisioning performed. This confirms the delay is still present. Recommend a metadata pre-check and short negative cache, caching only explicit missing-tag outcomes; auth, communication and arbitrary errors must not be cached as missing. That implementation remains open. AtTime timings are direct gateway RPCs, not OtOpcUa's raw-based evaluator.

Evidence committed in docs/plans/2026-10-13-historian-695-698-results.md.

Pushed commit 97668d26; PR: #699.

Full solution verified: 14,581 passed, 609 skipped, 0 failed across 62 suites (dotnet test ZB.MOM.WW.OtOpcUa.slnx --verbosity quiet, exit 0). Independent final review found no important defects. New fixes have not been deployed or live-tested end to end through OPC UA.

Live remeasurement completed with a newly commissioned temporary historian:read key (two-hour expiry; revoked after the run). Five sequential calls per operation through client 0.3.0 and the running local gateway/upstream AVEVA connection: | Operation | SysTimeSec range | Nonexistent tag range | |---|---|---| | Metadata | 48–299 ms, success | 41–89 ms, gateway exception | | Raw | 99–159 ms, success | 30.260–30.754 s, gateway exception | | Aggregate | 249–309 ms, success | 30.564–30.806 s, gateway exception | | AtTime | 88–140 ms, success | 61.074–61.601 s, gateway exception | Tag: OtOpcUa.Issue653.Nonexistent.20261013. No historian writes/provisioning performed. This confirms the delay is still present. Recommend a metadata pre-check and short negative cache, caching only explicit missing-tag outcomes; auth, communication and arbitrary errors must not be cached as missing. That implementation remains open. AtTime timings are direct gateway RPCs, not OtOpcUa's raw-based evaluator. Evidence committed in docs/plans/2026-10-13-historian-695-698-results.md. Pushed commit `97668d26`; PR: https://gitea.dohertylan.com/dohertj2/lmxopcua/pulls/699. Full solution verified: 14,581 passed, 609 skipped, 0 failed across 62 suites (`dotnet test ZB.MOM.WW.OtOpcUa.slnx --verbosity quiet`, exit 0). Independent final review found no important defects. New fixes have not been deployed or live-tested end to end through OPC UA.
Author
Owner

Fixed missing-tag latency in OtOpcUa Raw, Processed and AtTime. A bounded 4,096-name presence cache uses negative TTL 5 s and positive TTL 60 s; faults/cancellation are never cached as absence. A missing tag returns empty Raw and null/BadNoData at AtTime/Processed request timestamps without history RPCs. Unsupported aggregates still validate first.

Live revealed the deployed gateway misparses a missing GetTagMetadata response as Internal. The adapter therefore proves presence/absence using a filtered tag catalog stream and exact names, fully draining before caching. This does not treat Internal errors as missing; catalog errors still propagate. Wire regressions cover exact/wildcard name checks and a matching row followed by a stream fault.

Live updated data source, five calls per operation on OtOpcUa.Issue653.Nonexistent.20261013: Raw 228/0/0/0/0 ms; Count processed 2/0/0/0/0 ms; AtTime 1/0/0/0/0 ms, correct no-data results. One data source/cache: first Raw cold, later calls warm. All temporary read-only test keys verified revoked; no historian writes, provisioning or deployment changes.

Control limitation: SysTimeSec Raw timed out upstream with DeadlineExceeded through both the data source and a fresh original-package-client control (30,656 ms). The new checks are not the source of that timeout; healthy-tag live reads were not validated in this run. Direct gateway client missing-tag RPCs remain unchanged; OtOpcUa now avoids them.

Closing the fixed OtOpcUa issue.

Pushed commit 58977640 on fix/historian-653-followups, included in PR #699: #699 (awaiting merge).

Full final-tree solution: 14,600 passed, 609 skipped, 0 failed across 62 suites (dotnet test ZB.MOM.WW.OtOpcUa.slnx --verbosity quiet, exit 0). Final Gateway suite: 434 passed / 6 environment-gated skips. Independent final review found no important defects.

Evidence: docs/plans/2026-10-13-historian-653-696-results.md.

Fixed missing-tag latency in OtOpcUa Raw, Processed and AtTime. A bounded 4,096-name presence cache uses negative TTL 5 s and positive TTL 60 s; faults/cancellation are never cached as absence. A missing tag returns empty Raw and null/BadNoData at AtTime/Processed request timestamps without history RPCs. Unsupported aggregates still validate first. Live revealed the deployed gateway misparses a missing GetTagMetadata response as Internal. The adapter therefore proves presence/absence using a filtered tag catalog stream and exact names, fully draining before caching. This does not treat Internal errors as missing; catalog errors still propagate. Wire regressions cover exact/wildcard name checks and a matching row followed by a stream fault. Live updated data source, five calls per operation on OtOpcUa.Issue653.Nonexistent.20261013: Raw 228/0/0/0/0 ms; Count processed 2/0/0/0/0 ms; AtTime 1/0/0/0/0 ms, correct no-data results. One data source/cache: first Raw cold, later calls warm. All temporary read-only test keys verified revoked; no historian writes, provisioning or deployment changes. Control limitation: SysTimeSec Raw timed out upstream with DeadlineExceeded through both the data source and a fresh original-package-client control (30,656 ms). The new checks are not the source of that timeout; healthy-tag live reads were not validated in this run. Direct gateway client missing-tag RPCs remain unchanged; OtOpcUa now avoids them. Closing the fixed OtOpcUa issue. Pushed commit `58977640` on `fix/historian-653-followups`, included in PR #699: https://gitea.dohertylan.com/dohertj2/lmxopcua/pulls/699 (awaiting merge). Full final-tree solution: 14,600 passed, 609 skipped, 0 failed across 62 suites (`dotnet test ZB.MOM.WW.OtOpcUa.slnx --verbosity quiet`, exit 0). Final Gateway suite: 434 passed / 6 environment-gated skips. Independent final review found no important defects. Evidence: `docs/plans/2026-10-13-historian-653-696-results.md`.
Author
Owner

Merged PR #699 into master as 618d98e822. The merged tree exactly matches tested 58977640: full solution 14,600 passed, 609 skipped, zero failed across 62 suites. #653 and #695–#698 are closed; #694 remains open for historiangw#27.

Pending findings are now tracked explicitly:

  • lmxopcua#700: deployed OPC UA/live historian verification, after historiangw#29 restores the existing-tag control.
  • lmxopcua#701: optional concurrent cold/expiry cache coverage.
  • historiangw#29: live existing-tag Raw deadline failures.
  • historiangw#30: deploy/verify the existing missing-metadata sentinel fix.
  • historiangw#31: fail on a premature empty native catalog page (source-inspection finding; not reproduced live).
  • historiangw#32: correct API-key rotation flags and verify deployed unknown-ID revoke reporting.

No deployment changes were made. All temporary test keys were independently verified revoked.

Merged PR #699 into master as 618d98e8224ce1989677590094627e924c644c91. The merged tree exactly matches tested 58977640: full solution 14,600 passed, 609 skipped, zero failed across 62 suites. #653 and #695–#698 are closed; #694 remains open for historiangw#27. Pending findings are now tracked explicitly: - lmxopcua#700: deployed OPC UA/live historian verification, after historiangw#29 restores the existing-tag control. - lmxopcua#701: optional concurrent cold/expiry cache coverage. - historiangw#29: live existing-tag Raw deadline failures. - historiangw#30: deploy/verify the existing missing-metadata sentinel fix. - historiangw#31: fail on a premature empty native catalog page (source-inspection finding; not reproduced live). - historiangw#32: correct API-key rotation flags and verify deployed unknown-ID revoke reporting. No deployment changes were made. All temporary test keys were independently verified revoked.
Sign in to join this conversation.
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: dohertj2/lmxopcua#653