How steps are ordered

Trailbeam shows step A before step B only when an observed fact proves it. Each such fact is a source, recorded on the edge it proves and shown on the screen. Nothing is ever ordered by what usually causes what.

The four sources#

Trailbeam checks every ordered pair of recorded steps (A, B) against these rules. Each rule that holds is a direct edge: A before B.

Comparisons are strict. Equal times, equal counts or equal SQS timestamps (the same millisecond) prove nothing. SQS's timestamps are only compared with each other, never with a host clock.

clock#

The span interval runs from just before the request was sent to when the response came back, so A.end < B.start means SQS finished A before it could have started B. Python reads time.time_ns() (nanoseconds). Node.js reads Date.now() (whole milliseconds) and always rounds down, which can make two intervals look like they touch but never reverses "A ended before B started". A Lambda receive has no start, so clock never puts it after anything.

process_order#

The clocks often tie: a consumer sends its delete in the same millisecond its receive returned. The process itself knows the order, so every span records two ticks of a per-process counter:

tick() returns 1, 2, 3, ... and every span of one call (each batch entry, each message of a receive) shares that call's pair.

• Python: one counter for the whole process, behind a lock, shared by every thread. A forked child gets a new scope and restarts at 1 (os.register_at_fork). A call in flight across a fork gets no issued tick.
• Node.js: one counter per realm. The main thread has one and each worker_thread has its own scope. All async tasks in a realm share it.

Sharing across threads is sound: an edge needs A to have returned before B was issued, and two calls in flight at the same time never satisfy that, whichever threads made them. Ticks from different scopes are never compared, so process_order never orders steps across processes.

The Lambda wrapper takes one returned tick when the event arrives (no issued, since Lambda's poller made the call) and one tick, used as both issued and returned, when the outcome is decided. So a handler's outcome is after its own receive, and nothing is ordered before a Lambda receive by this source.

receive_count#

Delivery n comes before delivery n + 1 on the same queue. This orders redeliveries even when their intervals overlap, and it orders Lambda receives, which have no start.

sqs_timestamps#

Only the send and the first receive. SQS sets SentTimestamp and ApproximateFirstReceiveTimestamp from its own clock, so if the first is lower the send came first. This is what usually separates a send from a long-poll receive that was already waiting.

Chains, groups and conflicts#

Transitive. Trailbeam computes the transitive closure of all direct edges. A before B by one source and B before C by another puts A before C.

What the API returns. order.edges lists every direct edge with all the sources that prove it. order.edges_by_source counts edges per source. Each event's after lists only its immediate predecessors (the transitive reduction), each with sources, source (the first) and why.

Display order and groups. Trailbeam sorts the steps topologically. Among steps whose order is not proven, it breaks ties by end time, then start time, then insertion row: that keeps the listing stable and means nothing. It then cuts the list wherever every step above is proven before every step below. A piece with more than one step is a concurrent group. See Reading a timeline.

Conflicts. If the sources form a cycle (A before B by one source, B before A by another), Trailbeam finds every edge inside the cycle, drops those edges, recomputes the closure, lists them in order.conflicts, and adds the notice order_conflict. The steps on the cycle then share a group.

Inferred steps are not part of the edge set. They are placed by their anchors only. See Recorded and inferred steps.

Why Trailbeam won't guess#

Most tools sort steps by timestamp and stop there. For SQS that goes wrong exactly when you need it: in an incident, with two consumers racing and clocks a few milliseconds apart. A neat but wrong order sends you after the wrong process. So we made the opposite trade. Trailbeam draws an order only when it can name the fact that proves it, and shows that fact on the screen. When it can't, it says order unknown.

The cost is that some timelines show more concurrent boxes than you'd like. We think that's the right failure. A box that says "we don't know" is a prompt to look closer; a confident wrong order isn't. If you see a lot of boxes, the usual fix is upgrading old packages (schema 2 spans have no call-order ticks), not a smarter guess.

Worked example#

A send, a first receive whose poll overlapped it, a redelivery, and a delete in the same millisecond as the receive that preceded it.

"order": {
  "edges": [
    {"from": "e1", "to": "e2", "sources": ["sqs_timestamps"]},
    {"from": "e1", "to": "e4", "sources": ["clock"]},
    {"from": "e1", "to": "e5", "sources": ["clock"]},
    {"from": "e2", "to": "e4", "sources": ["clock", "process_order", "receive_count"]},
    {"from": "e2", "to": "e5", "sources": ["clock", "process_order"]},
    {"from": "e4", "to": "e5", "sources": ["process_order"]}
  ],
  "edges_by_source": {"clock": 4, "process_order": 3, "receive_count": 1, "sqs_timestamps": 1},
  "conflicts": []
}

• Send and receive 1 overlap, so clock gives nothing. The receive's SentTimestamp (40.004) is lower than its ApproximateFirstReceiveTimestamp (40.006), so sqs_timestamps orders them.
• Receive 2 to the delete is proven only by process_order: the delete was issued after receive 2 returned in the same process.
• Remove the SQS timestamps (or make them equal) and the send and receive 1 become one concurrent box.

Check an edge yourself#

Each recorded event carries process_order (scope, issued, returned, or null for schema version 2 spans), its times, queue, receive count and the two SQS timestamps in milliseconds. That is enough to recompute every edge in order.edges.

curl -s "http://127.0.0.1:4318/api/messages/$MESSAGE_ID" \
  | jq '.events[] | select(.inferred == false) | {id, type, start, end, process_order, receive_count,
        sent_timestamp_ms, first_receive_timestamp_ms}'

Edge cases#

Related#

• Reading a timeline
• Recorded and inferred steps
• Span contract: call order inside one process
• Span contract: order of steps in Trailbeam