Skip to content

Find out why a message ran twice

A customer was charged twice or an email went out twice. Find the second delivery, see which consumer ran it, and fix the cause.

Based on 9 repo files at 54ea61b

server/src/trailbeam_store/queries.py, server/src/trailbeam_store/timeline.py, server/src/trailbeam_store/server.py, server/src/trailbeam_store/web.py, server/tests/test_timeline.py, server/tests/test_api.py, docs/store-api.md, docs/span-contract.md, demo/README.md

On this page

Use this when the work for one message happened more than once: a double charge, a duplicate email, two rows where there should be one.

SQS standard queues deliver at least once, so a second delivery is normal. What matters is whether two deliveries both did the work, and why the second one happened.

1Step 1: List the duplicates#

Open /duplicates on Trailbeam (http://127.0.0.1:4318/duplicates), or call the API. The list is newest activity first.

shell
# Only messages whose work was done more than once
curl -s 'http://127.0.0.1:4318/api/duplicates?reason=succeeded_more_than_once&limit=20'

# Every message received more than once, on one queue
curl -s 'http://127.0.0.1:4318/api/duplicates?reason=received_more_than_once&queue=orders'
reason How Trailbeam counts it
received_more_than_once More than one stored trailbeam receive for the message ID, on any queue. A receive on the dead-letter queue counts.
succeeded_more_than_once More than one success. A success is a distinct delivery with an accepted delete (trailbeam.result = ok, joined to a receive by receipt-handle hash), or a distinct Lambda invocation with trailbeam.outcome = success.
(omitted) Either of the above.

Any other value returns 400 with {"error": "reason must be received_more_than_once or succeeded_more_than_once"}. limit is 1 to 1000 (default 100).

Each item is a message summary plus reasons:

json
{"messages": [{
  "message_id": "5fea7756-0ea4-451a-a703-a558b933e274",
  "state": "deleted", "source_queue": "orders", "current_queue": "orders",
  "in_dead_letter_queue": false, "dead_letter_queue_move": null,
  "deliveries": 2, "successful_deliveries": 2,
  "consumers": [{"service_name": "orders-worker", "client_id": "consumer-a"},
                {"service_name": "orders-worker", "client_id": "consumer-b"}],
  "first_seen": "2025-11-14T00:26:40.030000Z", "first_seen_clock": "host",
  "last_seen": "2025-11-14T00:27:21.000000Z",
  "reasons": ["received_more_than_once", "succeeded_more_than_once"]
}]}

Counting rules worth knowing:

  • A delete retried with the same receipt handle is one success, because Trailbeam counts distinct deliveries, not delete calls.
  • An accepted delete with a stale handle (stale_handle) is a success. SQS accepted it, so the consumer that sent it finished its work.
  • A delete that SQS rejected (failed) is not a success, even though the consumer probably did its work before trying to delete.
  • An accepted delete that could not be joined to a receive (unmatched_handle) is not counted.

2Step 2: Open the timeline#

shell
curl -s "http://127.0.0.1:4318/api/messages/$MESSAGE_ID" | jq '{state, deliveries, successful_deliveries,
  steps: [.events[] | {id, type, inferred, delivery, receive_count, status, error_code,
                       client: .consumer.client_id}]}'

For each delivery, compare the received event's consumer (service_name, client_id, pid, thread_name) and receive_count, then the deleted event that names the same delivery. A slow consumer on Amazon SQS looks like this:

Timeline sample
  1. 00:26:40.030Sentorders-api · queue orders
  2. 00:26:41.000Receiveddelivery 1 · receive count 1 · orders-worker (client consumer-a)
  3. inferredVisibility timeout expiredafter delivery 1, before delivery 2 · The visibility timeout expired before the delete: SQS accepted the delete, but the message was received again, so the delete came too late to remove it.
  4. 00:27:12.000Receiveddelivery 2 · receive count 2 · orders-worker (client consumer-b)
  5. 00:27:20.000Deletedelivery 1 · result ok · status stale_handle · consumer-a
  6. 00:27:21.000Deletedelivery 2 · result ok · status final · consumer-b

Consumer A was still working when the visibility timeout ran out. SQS made the message visible, consumer B received it, and both finished. A's delete is accepted but carries the handle of delivery 1, so its status is stale_handle. B's delete uses the handle of the latest receive, so it is final. successful_deliveries is 2.

3Step 3: Match the pattern#

What the timeline shows Cause Fix
Delivery 1, inferred Visibility timeout expired, delivery 2 to another consumer, then delivery 1's Delete stale_handle The first consumer ran longer than the visibility timeout. Both runs finished. Raise the queue's visibility timeout above the longest run, or extend it while working (below). Make your processing idempotent.
Same, but delivery 1's Delete is failed with error_code ReceiptHandleIsInvalid Same cause, on an SQS implementation that rejects old handles (ElasticMQ does). Only received_more_than_once lists it, yet the work ran twice. As above. Do not rely on succeeded_more_than_once alone on such queues.
Visibility changed with visibility_timeout_s 0, then the expiry with reason "ChangeMessageVisibility set the visibility timeout to 0, which made the message visible again at once." The consumer released the message on purpose, for example on a retryable error. Check that the first run did no side effects before it released the message.
Two Received steps with the same receive count and no expiry between them An at-least-once duplicate: SQS handed the same delivery to two consumers. Only idempotency fixes this.
An inferred Deliveries not observed step with a count Receives Trailbeam never saw: a consumer without Trailbeam, or spans that were lost. Instrument every consumer. See Keep every SQS span when you sample.
Lambda: Lambda outcome failed_exception or failed_invalid_response, then a second delivery with success The whole batch failed, so Lambda retried every record, including ones whose work was done. Return batchItemFailures for only the records that failed. See Debug Lambda timeouts and crashes.
A second Received on the dead-letter queue, after Moved to dead-letter queue Not duplicate work. DLQ receives count towards received_more_than_once. Nothing. See Trace a message to the dead-letter queue.

4Step 4: Check what Trailbeam can and cannot order#

Each observed event has an after list that says which earlier step it is proven to follow and why (clock, process_order, receive_count or sqs_timestamps). If delivery 1's delete and the expiry are in the same group and that group has concurrent: true, Trailbeam cannot tell whether the delete came before or after the timeout ran out. It does not guess. The screen shows that group as one box labelled "concurrent, order unknown".

shell
curl -s "http://127.0.0.1:4318/api/messages/$MESSAGE_ID" \
  | jq '.events[] | select(.type=="deleted") | {delivery, status, group, after: [.after[] | .why]}'

Prevent it#

Make your processing idempotent. Key the side effect on the SQS MessageId, which stays the same across redeliveries.

python
def handle(message):
    # A unique constraint on message_id makes the second insert fail
    inserted = db.execute(
        "INSERT INTO processed (message_id) VALUES (?) ON CONFLICT DO NOTHING",
        (message["MessageId"],)).rowcount
    if inserted:
        charge(message)
javascript
async function handle(message) {
  const { rowCount } = await db.query(
    'INSERT INTO processed (message_id) VALUES ($1) ON CONFLICT DO NOTHING', [message.MessageId]);
  if (rowCount) await charge(message);
}

Extend the visibility timeout while working if a run can take longer than the queue's timeout. Each call shows on the timeline as Visibility changed with its visibility_timeout_s. See Debug a visibility-timeout redelivery for a full heartbeat.

Instrument every consumer with the same key. A consumer without Trailbeam shows up only as Deliveries not observed. A consumer with a different TRAILBEAM_RECEIPT_HASH_KEY produces deletes that cannot be joined, and the timeline shows a key_mismatch notice.

shell
export TRAILBEAM_RECEIPT_HASH_KEY="$(openssl rand -hex 32)"   # generate once, share with every service