Repository navigation
fix(telemetry): write fixed-width UTC timestamps - #821
Merged
Merged
Conversation
Record timestamps were written with Instant.toString(). That method writes 0, 3, 6 or 9 fraction digits, depending on the value. So one record could hold startTime with 3 digits and endTime with 9. Destinations such as DynamoDB and CloudWatch Logs Insights compare these values as text. Text order equals time order only when every value has the same width. So mixed widths sort and filter incorrectly. emittedAt, startTime and endTime, on the record and on each operation, now use YYYY-MM-DDTHH:MM:SS.sssZ. This is the format of JavaScript's Date.prototype.toISOString(). Digits below the millisecond are dropped. The new internal Timestamps.format writes it. LambdaLogExporter uses the same method for the envelope timestamp, so its output is unchanged.
This comment has been minimized.
This comment has been minimized.
emittedAt has millisecond precision. With ON_CHANGE, one invocation can build two records in the same millisecond. One example is the last RUNNING record and the terminal record. So both records got the same emittedAt. SQSExporter builds the FIFO deduplication id from executionArn and emittedAt. DynamoDBExporter uses emittedAt as its default sort key. So SQS dropped the second message, and DynamoDB overwrote the first item. TelemetryPlugin now keeps the last emittedAt it assigned, in epoch milliseconds. If the clock is past that value, the clock is used. Otherwise the last value plus 1 ms is used. So emittedAt strictly increases within one plugin instance. One instance serves one invocation. This is the rule of aws/aws-durable-execution-sdk-js#1071. Hook threads can build records at the same time. No lock serializes the builds. So the last value is an AtomicLong, and the read and the update are one updateAndGet(prev -> Math.max(prev + 1, now)).
This comment has been minimized.
This comment has been minimized.
hln33
approved these changes
Oct 23, 2026
Contributor
Codex AI reviewNo actionable findings. The prior same-millisecond emission collision is addressed. Residual test risk: tests were inspected but not executed under the review constraints. Reviewed commit |
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
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 successfully deployed
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
By submitting this pull request, I confirm that my contribution is made under the terms of the Apache 2.0 license.
Summary
Every Durable Execution Telemetry record timestamp now has one fixed-width UTC format:
YYYY-MM-DDTHH:MM:SS.sssZ. The fraction always has 3 digits. The value always ends with the literalZ. This is the format of JavaScript'sDate.prototype.toISOString().Why:
startTimewith 3 fraction digits. In the same record it wroteendTimeandemittedAtwith 9, for example2026-10-23T18:42:44.078757096Z.Instant.toString(). It writes as many fraction digits as the value needs. It writes no fraction when the fraction is zero, for example2026-10-23T18:42:40Z.…40Zsorts after…40.500Z, becauseZsorts after.. The filterendtime >= '2026-10-23T18:42:46Z'excluded all 7 records that ended in that second.Changes:
emittedAt,startTimeandendTimeon the record, andstartTimeandendTimeon each operation, now go through one helper:Timestamps.format(Instant).DateTimeFormatter.ofPattern("uuuu-MM-dd'T'HH:mm:ss.SSS'Z'").withZone(ZoneOffset.UTC). Digits below the millisecond are dropped, not rounded. So.078757096becomes.078, and.999999999becomes.999.TelemetryPluginproduces all record timestamps. No other main code intelemetry-exporterproduces a record timestamp string.LambdaLogExporterhad its own identical formatter for the envelopetimestamp. It now calls the same helper. Its output is unchanged.public, becauseLambdaLogExporteris in theexporterspackage. I put it in the existingtelemetry.internalpackage, next toFatalErrors, instead of adding a method to the publicJsonclass. So the change adds no public API outsideinternal.LambdaLogExportersection now points to it.Python gets the same change in a sibling PR. JS already writes this format.
Testing
mvn -o -pl telemetry-exporter -am spotless:apply: no remaining changes.mvn -o -pl telemetry-exporter -am verify: BUILD SUCCESS. sdk: 1589 tests, 0 failures, 3 skipped. sdk-testing: 53 tests, 0 failures. telemetry-exporter: 243 tests, 0 failures.RecordTimestampFormatTest:Timestamps.formatgives.000Zfor zero nanos,.078Zfor 078757096 ns, and.999Zfor 999999999 ns.emittedAt,startTime,endTime, and each operation'sstartTimeandendTimematching^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{3}Z$, with the exact expected values for the three cases above.START.toString()(2026-08-05T00:00:00Z) as the recordstartTime. They now assert2026-08-05T00:00:00.000Z. Hand-built test records now use the same format as the plugin.Follow-up:
emittedAtis unique within one invocationemittedAthas millisecond precision. WithON_CHANGE, one invocation can build two records in the same millisecond, for example the last RUNNING record and the terminal record.SQSExporterbuilds the FIFO deduplication id fromexecutionArnandemittedAt.DynamoDBExporterusesemittedAtas its default sort key. So SQS dropped the second message, and DynamoDB overwrote the first item.Commit 28fa366 applies the rule of aws/aws-durable-execution-sdk-js#1071.
TelemetryPluginkeeps the lastemittedAtit assigned, in epoch milliseconds. If the clock is past that value, the clock is used. Otherwise the last value plus 1 ms is used. SoemittedAtstrictly increases within one plugin instance, and one instance serves one invocation. Hook threads can build records at the same time, so the last value is anAtomicLongupdated withupdateAndGet(prev -> Math.max(prev + 1, now)).New
EmittedAtOrderingTest: with a frozen clock, the RUNNING, RUNNING and SUCCEEDED records get.123Z,.124Zand.125Z. When the clock moves past the last value, the clock is used. 8 threads × 2000 calls give 16000 distinct values. Without the rule, all three tests fail.verify: telemetry-exporter 246 tests, 0 failures.