|
| 1 | +--- |
| 2 | +name: debug |
| 3 | +description: |
| 4 | + Investigate stuck runs and execution failures by tracing Symphony and Codex |
| 5 | + logs with issue/session identifiers; use when runs stall, retry repeatedly, or |
| 6 | + fail unexpectedly. |
| 7 | +--- |
| 8 | + |
| 9 | +# Debug |
| 10 | + |
| 11 | +## Goals |
| 12 | + |
| 13 | +- Find why a run is stuck, retrying, or failing. |
| 14 | +- Correlate Linear issue identity to a Codex session quickly. |
| 15 | +- Read the right logs in the right order to isolate root cause. |
| 16 | + |
| 17 | +## Log Sources |
| 18 | + |
| 19 | +- Primary runtime log: `log/symphony.log` |
| 20 | + - Default comes from `SymphonyElixir.LogFile` (`log/symphony.log`). |
| 21 | + - Includes orchestrator, agent runner, and Codex app-server lifecycle logs. |
| 22 | +- Rotated runtime logs: `log/symphony.log*` |
| 23 | + - Check these when the relevant run is older. |
| 24 | + |
| 25 | +## Correlation Keys |
| 26 | + |
| 27 | +- `issue_identifier`: human ticket key (example: `MT-625`) |
| 28 | +- `issue_id`: Linear UUID (stable internal ID) |
| 29 | +- `session_id`: Codex thread-turn pair (`<thread_id>-<turn_id>`) |
| 30 | + |
| 31 | +`elixir/docs/logging.md` requires these fields for issue/session lifecycle logs. Use |
| 32 | +them as your join keys during debugging. |
| 33 | + |
| 34 | +## Quick Triage (Stuck Run) |
| 35 | + |
| 36 | +1. Confirm scheduler/worker symptoms for the ticket. |
| 37 | +2. Find recent lines for the ticket (`issue_identifier` first). |
| 38 | +3. Extract `session_id` from matching lines. |
| 39 | +4. Trace that `session_id` across start, stream, completion/failure, and stall |
| 40 | + handling logs. |
| 41 | +5. Decide class of failure: timeout/stall, app-server startup failure, turn |
| 42 | + failure, or orchestrator retry loop. |
| 43 | + |
| 44 | +## Commands |
| 45 | + |
| 46 | +```bash |
| 47 | +# 1) Narrow by ticket key (fastest entry point) |
| 48 | +rg -n "issue_identifier=MT-625" log/symphony.log* |
| 49 | + |
| 50 | +# 2) If needed, narrow by Linear UUID |
| 51 | +rg -n "issue_id=<linear-uuid>" log/symphony.log* |
| 52 | + |
| 53 | +# 3) Pull session IDs seen for that ticket |
| 54 | +rg -o "session_id=[^ ;]+" log/symphony.log* | sort -u |
| 55 | + |
| 56 | +# 4) Trace one session end-to-end |
| 57 | +rg -n "session_id=<thread>-<turn>" log/symphony.log* |
| 58 | + |
| 59 | +# 5) Focus on stuck/retry signals |
| 60 | +rg -n "Issue stalled|scheduling retry|turn_timeout|turn_failed|Codex session failed|Codex session ended with error" log/symphony.log* |
| 61 | +``` |
| 62 | + |
| 63 | +## Investigation Flow |
| 64 | + |
| 65 | +1. Locate the ticket slice: |
| 66 | + - Search by `issue_identifier=<KEY>`. |
| 67 | + - If noise is high, add `issue_id=<UUID>`. |
| 68 | +2. Establish timeline: |
| 69 | + - Identify first `Codex session started ... session_id=...`. |
| 70 | + - Follow with `Codex session completed`, `ended with error`, or worker exit |
| 71 | + lines. |
| 72 | +3. Classify the problem: |
| 73 | + - Stall loop: `Issue stalled ... restarting with backoff`. |
| 74 | + - App-server startup: `Codex session failed ...`. |
| 75 | + - Turn execution failure: `turn_failed`, `turn_cancelled`, `turn_timeout`, or |
| 76 | + `ended with error`. |
| 77 | + - Worker crash: `Agent task exited ... reason=...`. |
| 78 | +4. Validate scope: |
| 79 | + - Check whether failures are isolated to one issue/session or repeating across |
| 80 | + multiple tickets. |
| 81 | +5. Capture evidence: |
| 82 | + - Save key log lines with timestamps, `issue_identifier`, `issue_id`, and |
| 83 | + `session_id`. |
| 84 | + - Record probable root cause and the exact failing stage. |
| 85 | + |
| 86 | +## Reading Codex Session Logs |
| 87 | + |
| 88 | +In Symphony, Codex session diagnostics are emitted into `log/symphony.log` and |
| 89 | +keyed by `session_id`. Read them as a lifecycle: |
| 90 | + |
| 91 | +1. `Codex session started ... session_id=...` |
| 92 | +2. Session stream/lifecycle events for the same `session_id` |
| 93 | +3. Terminal event: |
| 94 | + - `Codex session completed ...`, or |
| 95 | + - `Codex session ended with error ...`, or |
| 96 | + - `Issue stalled ... restarting with backoff` |
| 97 | + |
| 98 | +For one specific session investigation, keep the trace narrow: |
| 99 | + |
| 100 | +1. Capture one `session_id` for the ticket. |
| 101 | +2. Build a timestamped slice for only that session: |
| 102 | + - `rg -n "session_id=<thread>-<turn>" log/symphony.log*` |
| 103 | +3. Mark the exact failing stage: |
| 104 | + - Startup failure before stream events (`Codex session failed ...`). |
| 105 | + - Turn/runtime failure after stream events (`turn_*` / `ended with error`). |
| 106 | + - Stall recovery (`Issue stalled ... restarting with backoff`). |
| 107 | +4. Pair findings with `issue_identifier` and `issue_id` from nearby lines to |
| 108 | + confirm you are not mixing concurrent retries. |
| 109 | + |
| 110 | +Always pair session findings with `issue_identifier`/`issue_id` to avoid mixing |
| 111 | +concurrent runs. |
| 112 | + |
| 113 | +## Notes |
| 114 | + |
| 115 | +- Prefer `rg` over `grep` for speed on large logs. |
| 116 | +- Check rotated logs (`log/symphony.log*`) before concluding data is missing. |
| 117 | +- If required context fields are missing in new log statements, align with |
| 118 | + `elixir/docs/logging.md` conventions. |
0 commit comments