Skip to content

fix(telemetry): write fixed-width UTC record timestamps - #821

Merged
ParidelPooya merged 3 commits into
mainfrom
fix/telemetry-timestamp-format
Oct 23, 2026
Merged

ParidelPooya merged 3 commits into
mainfrom
fix/telemetry-timestamp-format

Conversation

@ParidelPooya

@ParidelPooya ParidelPooya commented Oct 23, 2026 •

Copy link
Copy Markdown
Contributor

Summary

Every Durable Execution Telemetry record timestamp now uses one format: YYYY-MM-DDTHH:MM:SS.sssZ. The fraction always has exactly 3 digits. The suffix is always Z. JavaScript's Date.prototype.toISOString() writes the same format.

The change covers emittedAt, startTime and endTime on the record, and startTime and endTime on each operation. One helper, _format_record_timestamp() in plugin.py, now produces all of them. It converts the time to UTC. It then calls isoformat(timespec="milliseconds"), which truncates microseconds. It does not round.

Example: 2026-10-23T18:42:40.784119Z becomes 2026-10-23T18:42:40.784Z. A time with 0 microseconds was 2026-10-23T18:42:40Z. It is now 2026-10-23T18:42:40.000Z.

Why

  1. A deployed test ran the JS, Python and Java exporters on the same workflow.
  2. Python wrote 6 fraction digits, for example 2026-10-23T18:42:40.784119Z.
  3. Python's isoformat() writes no fraction when microseconds are 0.
  4. JS always writes 3 digits. Java writes 3 or 9.
  5. DynamoDB, CloudWatch Logs Insights, and string columns compare these values as text.
  6. Text order equals time order only when every value has the same width.
  7. In the test, …40Z sorted after …40.500Z.
  8. In the test, endtime >= '2026-10-23T18:42:46Z' excluded all 7 records that ended in that second.
  9. So all SDKs will write one fixed-width format. JS already writes it.

Unchanged

  • A datetime inside a user's operation result still becomes isoformat(). That value is user data, not a record timestamp.
  • The LambdaLogExporter envelope timestamp already had 3 digits.
  • exporters/_common.py parsing already accepts the new format.

Other edits

  • README: states the timestamp format next to the record schema description.
  • truncation.py and otel_exporter.py: comments now describe the fixed-width format.
  • test_plugin.py: two assertions pinned 2026-01-01T00:00:00Z. They now expect 2026-01-01T00:00:00.000Z.
  • New tests/test_timestamp_format.py: asserts ^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{3}Z$ for all 5 record timestamp fields of an emitted record. It covers 0 microseconds (.000Z), truncation (784119 µs gives .784Z, 999999 µs gives .999Z), and a +05:30 aware datetime converted to UTC.

Testing

  • pytest -n 8 packages/aws-durable-execution-sdk-python-telemetry-exporter/tests: 282 passed, 1 failed. The failure is test_package_metadata.py::test_public_version_matches_installed_stable_release. It fails locally because the installed package metadata is stale. The change does not touch it.
  • mypy on the telemetry exporter src and tests: no issues.
  • hatch fmt --check in the telemetry exporter package: passed.
  • lintcommit.py on the commit: passed.

Java gets the same change in a sibling PR. JS already writes this format.

emittedAt strictly increases within one invocation

emittedAt has millisecond precision. In on-change mode, one invocation can build two records in the same millisecond. The SQS FIFO deduplication id is executionArn:emittedAt. The default DynamoDB sort key is emittedAt. So equal values made SQS drop a message and made DynamoDB overwrite an item. So commit e06600a makes emittedAt strictly increase within one plugin instance, which serves one invocation. Each record takes the current time, truncated to milliseconds, when it is later than the last emittedAt. Otherwise it takes the last value plus 1 millisecond. The value is chosen during snapshot admission, under _lock. JS uses the same rule: aws/aws-durable-execution-sdk-js#1071. New tests in tests/test_timestamp_format.py freeze the clock and expect .123Z, .124Z, .125Z for RUNNING, RUNNING and SUCCEEDED.

Record timestamps now use YYYY-MM-DDTHH:MM:SS.sssZ. The fraction always
has 3 digits. The plugin converts each time to UTC and truncates it to
milliseconds. JavaScript's Date.prototype.toISOString() writes the same
format.

Before, isoformat() wrote 6 fraction digits. It wrote no fraction when
microseconds were 0. Stores compare these values as text. Text order
equals time order only when every value has the same width. So mixed
widths sorted records out of time order.
@ParidelPooya
ParidelPooya temporarily deployed to ai-pr-review-runtime October 23, 2026 19:14 — with GitHub Actions Inactive
@ParidelPooya
ParidelPooya temporarily deployed to ai-pr-review-runtime October 23, 2026 19:15 — with GitHub Actions Inactive
@github-actions

This comment has been minimized.

emittedAt has millisecond precision. In on-change mode, one invocation
can build two records in the same millisecond, for example RUNNING and
then the terminal record. The SQS FIFO deduplication id is
executionArn:emittedAt. The default DynamoDB sort key is emittedAt. So
SQS dropped the second message, and DynamoDB overwrote the first item.

So emittedAt now strictly increases within one plugin instance. The
instance serves one invocation. The instance keeps the last emittedAt in
epoch milliseconds. Each record takes the current time, truncated to
milliseconds, when it is later than the last value. Otherwise it takes
the last value plus 1. The JavaScript plugin uses the same rule.

Record building runs outside _lock by design, because it runs customer
transforms. Snapshot admission runs under _lock, and builds on
different threads can be admitted concurrently. So the value is chosen
during admission and carried on the snapshot to the build.
@ParidelPooya
ParidelPooya temporarily deployed to ai-pr-review-runtime October 23, 2026 20:07 — with GitHub Actions Inactive
@github-actions

This comment has been minimized.

@ParidelPooya
ParidelPooya temporarily deployed to ai-pr-review-runtime October 23, 2026 22:20 — with GitHub Actions Inactive
@github-actions

Copy link
Copy Markdown
Contributor

Codex AI review

One P2 remains at packages/aws-durable-execution-sdk-python-telemetry-exporter/src/aws_durable_execution_sdk_python_telemetry_exporter/plugin.py:513: emission identities can collide across resumed invocations. Tests were not executed, per the read-only review constraint.

Reviewed commit 1c6664fa45e7f13a60bc660eb71638df76610722. Workflow run

ParidelPooya added a commit to aws/aws-durable-execution-sdk-js that referenced this pull request Oct 23, 2026
## Summary

`emittedAt` has millisecond precision. With `emitMode: "on-change"`, two
records of one execution can be built within the same millisecond, for
example a RUNNING record and the final record. They then get the same
`emittedAt`.

Two exporters key on `executionArn` + `emittedAt`:

- `SQSExporter` derives the FIFO deduplication id from
`executionArn:emittedAt`. So SQS dropped the second message as a
duplicate, and that can be the final record.
- `DynamoDBExporter` uses `emittedAt` as its default sort key. So the
second item overwrote the first.

This change makes `emittedAt` strictly increase within one plugin
instance, which serves one invocation. A record built in the same
millisecond as the previous one, or earlier, gets the previous value
plus 1 ms. Otherwise it gets the current time. The format and the record
shape do not change.

Codex raised this on the Python and Java PRs that pin record timestamps
to the same millisecond format
(aws/aws-durable-execution-sdk-python#821,
aws/aws-durable-execution-sdk-java#821). JS already wrote milliseconds,
so it already had the collision. Those two PRs get the same rule.

## Testing

- Two new tests in `index.test.ts`:
- With `Date.now` frozen, an on-change invocation's three records
(RUNNING, RUNNING, SUCCEEDED) get `.123Z`, `.124Z`, `.125Z`.
- When the clock moves past the previous record, the record uses the
current time.
  - Both tests fail without the change.
- Exporter: build passes, 161 tests pass.
- `biome ci` is clean on the exporter source and the CHANGELOG.
@ParidelPooya
ParidelPooya merged commit 102dd62 into main Oct 23, 2026
18 checks passed
@ParidelPooya
ParidelPooya deleted the fix/telemetry-timestamp-format branch October 23, 2026 22:33
ParidelPooya added a commit to aws/aws-durable-execution-sdk-js that referenced this pull request Oct 23, 2026
…#1070)

## Summary

A deployed test ran the same workflow on the JS, Python, and Java
exporters, writing to S3 and Aurora. It found two problems with how
record timestamps are compared.

1. The bundled Athena table declares `emittedat`, `starttime`,
`endtime`, and the operation `starttime`/`endtime` as `string`. So
Athena compares them as text. Measured on the deployed records: `endtime
>= '2026-10-23T18:42:46Z'` returned none of the 7 records that ended in
that second, because `.` sorts before `Z`. The same filter on a
`timestamp` column returned all 7.
2. `list_executions` interpolated `since` and `until` as given. On
destinations that compare text (DynamoDB, CloudWatch Logs Insights), a
bound without a fraction, or with an offset such as `-07:00`, returned
the wrong records. With an offset the error is hours.

Changes:

- **Athena table:** the CDK Glue table (`cdk/stack.ts`) and the
telemetry-core DDL (`athena.ts`) declare those columns as `timestamp`.
The S3 objects do not change; the OpenX JSON SerDe parses the ISO
strings into the typed columns.
- **Athena schema prompt (`schema.ts`):** the columns are listed as
`timestamp (UTC)`. A new dialect rule says to compare them with
`TIMESTAMP` literals or timestamp expressions, never strings.
- **MCP `list_executions`:** a new `normalizeTimestamp` validates each
bound, including the calendar (it rejects `2026-02-30`, which
`Date.parse` would roll forward to March 2). A bound with no offset is
read as UTC. Each dialect then writes its own literal:
- Typed time columns (Athena `timestamp`, Aurora and Redshift
`timestamptz`, OpenSearch `date`) compare instants. The bound keeps
every digit the caller gave, because an existing table can hold values
finer than a millisecond. Athena gets a `TIMESTAMP '…'` literal; the
others get a quoted UTC string.
- Text comparisons (DynamoDB, Logs Insights) get the stored format: UTC,
3 fraction digits, `Z`. A finer bound is rounded so it selects the same
records: `since` up to the next millisecond, `until` down.
- **Docs:** the exporter README has a new "Timestamps" section that
states the format contract. The MCP README describes how bounds are
read. Both CHANGELOG entries are under Fixed. The Athena entry includes
a migration note: a table created earlier keeps `string` columns until
it is recreated or altered.

JS already writes every record timestamp with `toISOString()`, so the
record format does not change here. Python and Java change to the same
fixed-width format in sibling PRs:

- aws/aws-durable-execution-sdk-python#821
- aws/aws-durable-execution-sdk-java#821

## Testing

- Deployed check against the 18 real records in S3:
- I created a temporary Athena table from the new `buildCreateTableDdl`
output, then dropped it.
- The SQL that `buildListExecutionsSql` now builds for `since:
"2026-10-23T11:42:46-07:00"` returned the 3 executions in that window,
from all three SDKs.
  - `date_diff('millisecond', starttime, endtime)` equals `durationms`.
  - Operation `starttime`/`endtime` read as timestamps.
  - A string comparison fails with `TYPE_MISMATCH`, as the prompt says.
- New `timeBounds.test.ts` (21 tests): the normalized forms, rejection
of invalid dates and injection attempts, text order equal to time order
after normalization, and the literal per destination. Updated the two
`injection.test.ts` expectations.
- Package tests: MCP 427, core 385, exporter 159, vscode 34, desktop 48.
All passed.
- `biome ci` on the repo: clean.
- Not run: a CDK deploy of the changed Glue table.

This branch was previously deployed

1 inactive deployment
ai-pr-review-runtime — 1c6664fa Deployed Oct 23, 2026 by ParidelPooya via ai-pr-review / Codex review / Generate Codex review #2223
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants