[morgan-wowk]

Problem: The only view into how long the orchestrator's sweep takes per execution, and how long a finished task waits to be marked done, is a flood of per-visit INFO logs.

Objective: Measure both as metrics, so the per-visit logs can be removed in #419.

sequenceDiagram
    participant C as Container
    participant O as Orchestrator sweep
    participant DB as Database
    participant U as User
    C->>C: Container finishes
    Note over C,U: completion_lag starts. The task still shows RUNNING
    loop Every execution ahead of it in the running queue
        O->>DB: queries phase: pick the next row, load it, find its nodes
        O->>O: processing phase: launcher refresh, finish it if it ended
        Note over O,DB: one refresh.duration sample per visit
    end
    O->>DB: queries phase: this execution's turn
    O->>C: processing phase: the launcher reports the container ended
    O->>O: upload its log, read its outputs
    O->>DB: commit SUCCEEDED or FAILED
    Note over C,U: completion_lag stops
    DB-->>U: The task shows done and downstream tasks start

Loading

completion_lag is the delay users feel between a task finishing and Tangle showing it as done. refresh.duration explains a high lag: a high sample count means many visits were ahead of it, and long samples mean each visit was slow. Long queries samples point at the database, and long processing samples point at the launcher or storage.

• container_execution.refresh.duration: seconds per running container execution refresh, split by container_execution.refresh.phase. The two phases don't overlap and add up to the refresh. What contributes, by phase:
  • queries: the select that picks the least recently refreshed PENDING or RUNNING row, which slows with database load and the number of active executions.
  • queries: loading that row, including its JSON columns.
  • queries: looking up its execution nodes.
  • processing: the cancellation check, one pipeline run query per execution node.
  • processing: the launcher refresh, for example a Kubernetes read or a Davies API call.
  • processing: saving changed launcher data.
  • processing: for an ended container, uploading its log, checking and reading its outputs, queueing downstream tasks, and cleaning up the workload.
  • processing: for a cancelled one, uploading its log and terminating it.
• container_execution.completion_lag.duration: seconds from a container ending, as reported by its launcher, to the orchestrator committing its SUCCEEDED or FAILED status, by that committed container_execution.status. What contributes:
  • Waiting for the sweep to reach the execution. The running queue goes least recently refreshed first, so this grows with the number of active executions, the 1s pause between sweeps, and the time the queued queue takes first, for example during a launch burst.
  • The launcher noticing the end, for example a Kubernetes watch or cache that hasn't caught up yet.
  • Retriable refresh errors that push the refresh to a later sweep.
  • Finishing the execution before the commit: uploading the log, checking that outputs exist, reading their size and hash, preloading small values, and queueing downstream tasks.
  • Timestamp precision. Kubernetes end times are whole seconds, so values can read up to 1s high.

[yuechao-qin]

(AI Assisted)

Approve with one change. The instrumentation is placed where it can see what it claims: the refresh timing is recorded in a finally:, so every visit counts including the early returns, and the completion lag is recorded after the session.commit() that makes the status durable, carrying the committed status rather than the launcher's. Both helpers degrade safely — a missing or naive ended_at returns instead of raising — and the advisory bucket boundaries are actually honoured, since the MeterProvider configures no Views. One measurement bug to fix first: the two phases overlap, so they are not a split of the refresh (m1).

#	Severity	Topic
m1	🔹 minor	the two phases overlap, so queries + processing is not the refresh's duration
N1	▫️ nit	the PR body names the phases querying/processing; the code emits queries

[morgan-wowk]

Verified locally in OSS orchestrator and known wrappers.