Logs are out of order
Scope
k8s worker, all action execution logs. Logs shown for an execution (run view, run logs API, live websocket) can come out in a different order from the one the action wrote them in.
Why ordering is not guaranteed today
Nothing that travels from the worker to the runner says where a batch of log lines belongs, so the runner can only store lines in the order it happens to process them.
- The message carries no position.
ExecutionLogsUpdatedis justexecution_id+logs(core/ryax/common/messaging/messages/worker_messages_v2.proto:15-18). There is no sequence number and no timestamp. - The worker sends logs from two sources. It publishes the live pod log stream in batches, then a final full-log fetch that sends the tail the stream missed (
core/ryax/worker_k8s/application/execution_handlers.py:65-100,:510-521). The pod log read is done withouttimestamps=true, so the lines carry no time either. - The runner consumes without a bound and without per-execution serialization.
set_qos(prefetch_count=0)(core/ryax/common/messaging/consumer.py:110). Two batches for the same execution can be handled concurrently bynew_log_lineV2(core/ryax/runner/application/handlers/v2_execution_handlers.py:316). - The runner's
indexis computed at arrival.ActionLogs.appendhands outself.indexand increments it (core/ryax/runner/domain/action_logs/action_logs_entities.py:39-43), so it records arrival order, not emission order. Two concurrent appends both read the same startingindexand write overlapping values. - The read does not even sort by it.
get_logs_as_stringdoesselect(LogLine).where(logs_id == …)with noORDER BY(core/ryax/runner/infrastructure/database/repositories/action_logs_repository.py:43-53). Both the run logs API (action_logs_service.get_logs) and the trigger-logs websocket go through it, so Postgres is free to return rows in any order. The ORM relationship hasorder_by=LogLine.index, but this query bypasses it.
Proposal
Have the producer stamp the position, not the consumer:
- Worker: give each
ExecutionLogsUpdateda monotonically increasing per-execution sequence number, covering both the stream batches and the final fetch. Alternatively, read pod logs withtimestamps=trueand send a timestamp per line. The timestamp also helps across a worker restart, where a counter would reset. - Proto: add the field to
ExecutionLogsUpdated(e.g.uint64 sequenceand/or a per-line timestamp). - Runner:
- Store the worker-provided position in
log_linesinstead of the arrival counter. - Read with
ORDER BYit. - Order the live websocket push the same way, or let the front reorder by it.
- Store the worker-provided position in
Not done yet
This is from code reading. I have not reproduced the reordering live. A test would be an action that prints numbered lines quickly for longer than one stream batch, then a check of the order returned by GET /api/runner/…/logs.
Edited by Michael Mercier