# Отладка ИИ-агентов: наблюдаемость, которой нам не хватало в первый же день > Агент сжёг 4 доллара и 90 вызовов инструментов на задаче, которая должна была стоить три вызова, а мы смотрели в пустой терминал. Вот инструментарий, превративший гадание в двухминутную диагностику — /info, /report и /context из Octomind, лог сессии в zstd, трассировка через RUST_LOG, --format jsonl и OctoHub впереди, чтобы перехватывать каждый upstream-запрос. Агент работал уже шесть минут. Спиннер всё ещё крутился. Когда я его убил, `/info` показал счёт в **$4,18**, а `/report` насчитал восемьдесят девять вызовов инструментов на задаче, которую я оценил в три вызова и пару центов. Он прочитал один и тот же файл одиннадцать раз. Он искал символ через grep, получал пустой результат, переформулировал grep, получал ещё один пустой результат — и продолжал это делать, вежливо, уверенно, дорого, потому что ничто в цикле не говорило ему остановиться. Хуже всего были не четыре доллара. Хуже было то, что я понятия не имел, _почему_, пока не пошёл разбираться. Агент не выбрасывает стектрейс, когда идёт вразнос. Он не падает. Он просто тихо делает не то, рапортует об успехе и выставляет счёт. Снаружи блестящий прогон и катастрофический выглядят одинаково: текст летит мимо, инструменты срабатывают, в конце ответ. Эта статья — тот инструментарий, который мне хотелось бы подключить до того прогона, а не после. Всё это есть в [Octomind](https://github.com/Muvon/octomind), нашем рантайме агентов на Rust с открытым исходным кодом, а в последнем разделе перед ним встаёт [OctoHub](https://github.com/Muvon/octohub) — чтобы перехватить единственное, что сам агент показать не может: сырые байты, которые на самом деле ушли в модель. --- ## Почему агенты падают молча Традиционный софт падает громко. Null deref, 500-я, проваленный assert — у сбоя есть форма, место, номер строки. У сбоев агентов ничего этого нет, потому что с точки зрения рантайма не сломалось ничего. Каждый вызов API вернул 200. Каждый инструмент вышел с кодом 0. Модель на каждом шаге выдавала грамматически верный и правдоподобный текст. _Совокупное_ поведение было неверным, но ни одна отдельная операция — нет. На практике сбои группируются в четыре формы, и каждая невидима ровно в тот момент, когда вы хотели бы её поймать: - **Не тот инструмент, та же уверенность.** Модель тянется к `grep`, когда надо было прочитать файл, или бьёт в обобщённый shell, когда рядом есть точный инструмент. Она не колеблется — неверный выбор инструмента снаружи выглядит точно так же, как верный. (Мы написали целую статью о сужении набора инструментов ради борьбы с этим: [кастомные MCP должны жить в вашем репозитории](/blog/custom-mcps-belong-in-your-repo).) - **Усечение контекста.** Диалог вырос за пределы окна, сработало сжатие, и факт, нужный агенту, был ужат и потерян. Теперь он рассуждает по памяти с потерями, а шва вы не видите. - **Разогнавшиеся циклы.** Пустой результат → переформулировать → пустой результат → переформулировать. Каждый ход по отдельности разумен. Багом является сам паттерн, и замечаете вы его только по числу вызовов инструментов. - **Взрывы токенов.** Инструмент сбросил в контекст файл на 200 КБ, или один аргумент вызова раздулся — и теперь каждый последующий ход пересылает всё это заново. Стоимость становится сверхлинейной, и единственный симптом — счёт. Нельзя отлаживать то, чего не видишь. Поэтому первая задача — сделать прогон наблюдаемым, и постфактум, и во время. --- ## Уровень 0: `/info` — куда ушли деньги Самый быстрый вопрос для ответа — «сколько эта сессия реально стоила и какой формы». Внутри любой интерактивной сессии `/info`: ``` ╭ /info │ session my-feature-x │ model openrouter:anthropic/claude-sonnet-5 │ tokens 214,883 total │ breakdown 18,402 in · 9,114 out · 184,201 cache rd · 2,890 cache wr · 276 reasoning │ cost $4.18661 │ throughput 41.3 tok/s ╰ /info my-feature-x ``` Каждое поле здесь — диагностика. Тем, что вскрыло мой случай с разогнавшимся циклом, была строка **breakdown**. `184,201 cache rd` против `18,402 in` означает, что один и тот же контекст перечитывался почти на каждом ходу — подпись цикла, который всё дописывает и никогда не разрешается. Число вызовов инструментов, которое это подтвердило, живёт уровнем ниже — в `/report`. `/info` также раскладывает траты за пределами основного цикла — собственные токены и стоимость модели сжатия, расстановка кэш-маркеров с итогами чтения/записи, любые субагенты и супервизор получают каждый свою секцию — так что при высоком счёте видно, съела ли его основная беседа или фоновый процесс. Если сессия хоть раз сжималась, `/info` показывает блок **compression**: сколько сжатий сработало, сколько сообщений удалено, сколько токенов сэкономлено, средний коэффициент. Это ваше раннее предупреждение об усечении. Если вы видите три сжатия уровня проекта в короткой сессии, агент что-то забывал — и об этом стоит знать прежде, чем доверять его выводам. --- ## Уровень 1: `/report` — стоимость по запросу, а не по сессии `/info` — это итог сессии. `/report` — это детализированный чек: одна строка на каждый запрос пользователя, реконструированный из лога сессии: ``` ╭ /report │ # request cost tools task ai proc │ ── ─────────────────────────────── ──────── ───── ─────── ─────── ─────── │ 1 add a health-check endpoint $0.04120 3 18s 12s 1s │ 2 wire it into the router $0.02980 2 11s 9s 1s │ 3 why is the test flaky $3.98120 84 5m 31s 3m 40s 20s │ ── ─────────────────────────────── ──────── ───── ─────── ─────── ─────── │ Σ 3 request(s) $4.05220 89 6m 00s 4m 01s 22s ╰ /report 3 request(s) · $4.05220 ``` Вот оно. Запрос 3 — «why is the test flaky» — это весь счёт. Восемьдесят четыре вызова инструментов на один вопрос. Два благополучных запроса обрамляют одну катастрофу, и без разбивки по запросам все они сливаются в общий итог сессии. `/report` — это как вы находите, _какой именно промпт_ отправил агента под откос; а это и есть тот вопрос, на который надо ответить прежде, чем что-то чинить. Колонки разделяют время `task` (весь запрос, от начала до конца) и время `ai` (только вызовы модели). Когда `task` сильно превышает `ai` — ваши инструменты медленные. Когда они идут вровень — модель делает много round-trip'ов, снова подпись цикла. --- ## Уровень 2: `/context` — прочтите, о чём агент на самом деле думает Стоимость и счётчики говорят, _что_ что-то пошло не так. Чтобы увидеть _что именно_, читаешь сообщения. `/context` выгружает живой диалог как структурированный JSON, с фильтрами: ``` /context # всё /context large # только сообщения длиннее 1000 символов — найди пожирателя контекста /context tool # только результаты инструментов — посмотри, что агент реально получил /context assistant # только ходы самой модели ``` `/context large` — то, к чему я тянусь при взрывах токенов. Он выносит на поверхность ровно те сообщения, что раздувают окно — обычно один результат инструмента, вернувший гигантский файл или огромный JSON-блоб, — и теперь вы знаете, какой инструмент научить пагинации или усечению. В моей катастрофе с flaky-тестом `/context tool` показал восемьдесят с лишним пустых результатов `grep`. Модель ни разу не сменила стратегию, потому что ничто не говорило ей, что стратегия не работает. Чтение результатов инструментов сделало цикл очевидным секунд за пятнадцать. --- ## Уровень 3: лог сессии — полная, воспроизводимая запись Всё вышеперечисленное читает из одного артефакта: файла сессии. Octomind пишет каждую сессию в ``` ~/.local/share/octomind/sessions/.jsonl.zst ``` Это сжатый zstd JSONL — по одному JSON-объекту на строку. Большинство строк — это сырые сообщения диалога (`role: user|assistant|tool|system`). Вперемешку идут типизированные маркеры, нужные рантайму для реконструкции состояния при возобновлении: | Маркер | Что записывает | | ------------------------------------- | ----------------------------------------------------------------------------------- | | `STATS` | Текущие итоги — стоимость, время API, время инструментов — на этой точке | | `COMPRESSION_POINT` | Сработало сжатие: тип, удалённые сообщения, сэкономленные токены | | `RESTORATION_POINT` | Чекпоинт `/done` — прежние сообщения схлопываются при перезагрузке | | `KNOWLEDGE_ENTRY` | Факт, извлечённый при сжатии, переинъецируемый при возобновлении | | `COMMAND` | Команда рантайма (`/model`, `/role`, `/effort`…), воспроизводимая при возобновлении | | `PLAN_SNAPSHOT` / `SCHEDULE_SNAPSHOT` | Активный план / расписание, чтобы пережить перезапуск | Этот файл — истина в первой инстанции. `/report` буквально генерируется распаковкой этого файла и проходом по записям `STATS` и `USER`/`COMMAND`, чтобы раскидать стоимость между запросами. То же самое можно сделать самому: ```bash zstd -dc ~/.local/share/octomind/sessions/my-feature-x.jsonl.zst \ | jq -r 'select(.role == "tool") | "\(.content | length)\t\(.name)"' \ | sort -n | tail ``` Этот one-liner ранжирует результаты инструментов по размеру прямо из лога — ваши пожиратели токенов, даже не открывая сессию. Поскольку лог — это append-only JSONL, он ещё и идеальный артефакт для replay: возобновите ровно ту же сессию через `octomind run --resume my-feature-x`, или возьмите самую свежую для текущего каталога через `--resume-recent`, и рантайм восстановит состояние из этих самых строк. --- ## Уровень 4: `RUST_LOG` — когда нужно заглянуть внутрь рантайма Лог сессии показывает, _каким был диалог_. Когда нужно увидеть, _что сделал рантайм_ — почему не загрузился MCP-сервер, почему был пропущен инструмент, что на самом деле вернул провайдер — включайте трассировку. Octomind построен на крейте `tracing`, за стандартной переменной окружения `RUST_LOG`. В CLI-режиме подписчик трассировки **намеренно** не создаётся, пока вы его не попросите — пользователи получают чистый цветной вывод, а не пожарный шланг. Поставьте `RUST_LOG` — и шланг открывается: ```bash # Всё на уровне debug RUST_LOG=debug octomind run # Сузить до одного модуля — на практике куда полезнее RUST_LOG=octomind::mcp=debug octomind run # Несколько областей, смешанные уровни RUST_LOG=octomind::session=debug,octomind::mcp=trace octomind run ``` Область важна. `RUST_LOG=debug` на загруженной сессии нечитаем; `RUST_LOG=octomind::mcp=debug`, когда инструмент не появляется, точно скажет вам, какой кандидат был принят или отвергнут и почему. Это тот уровень, на котором «агент не видит мой инструмент» перестаёт быть загадкой. В режимах структурированного вывода — ACP и WebSocket — stdout и stderr зарезервированы под протокол, поэтому трассировка идёт в файлы: ``` ~/.local/share/octomind/logs/acp-debug.log ← трассировка ACP ~/.local/share/octomind/logs/acp-errors.jsonl ← ошибки ACP, структурированно ~/.local/share/octomind/logs/websocket-debug.log ← трассировка WebSocket ``` Если вы запускаете Octomind за редактором по ACP и что-то идёт не так — улики живут в этих файлах. --- ## Уровень 5: `--format jsonl` — направьте прогон в свой собственный тулинг Всё предыдущее — для человека, читающего терминал. Как только агент попадает в CI или пайплайн, прогон нужен как поток структурированных событий, по которым можно делать проверки. `octomind run --format jsonl` выдаёт по одному JSON-объекту на строку — тот же внутренний поток событий, что использует WebSocket-сервер, — помеченный по `type`: ```bash echo "audit the auth module" | octomind run developer:general --format jsonl ``` Каждая строка — отдельное событие. Варианты, которые вам важны: | `type` | Несёт | | ------------- | -------------------------------------------------------------------------------------------------------------------------------- | | `assistant` | Фрагмент ответного текста модели | | `thinking` | Содержимое рассуждений, отдельно от ответа | | `tool_use` | `tool`, `tool_id`, `server`, `params` — агент собирается действовать | | `tool_result` | `tool`, `content`, `success` — что вернулось | | `cost` | `session_tokens`, `session_cost`, `input_tokens`, `output_tokens`, `cache_read_tokens`, `cache_write_tokens`, `reasoning_tokens` | | `error` | Сообщение о сбое | | `injected` | Не-пользовательский ход — запланированный таймер, фоновый агент, skill — со своим `source_kind` | | `skill` | Skill активирован, использован или забыт | Теперь режимы сбоя становятся проверками. Считайте события `tool_use` и роняйте сборку, если один запрос превышает порог — это ваша растяжка против разогнавшихся циклов. Следите за `session_cost` в событии `cost` и алертите при превышении бюджета. Фильтруйте `tool_result` по `success: false`. Агент, который раньше падал молча, теперь падает так, что это ловит `jq`: ```bash echo "run the migration check" \ | octomind run --format jsonl \ | jq -c 'select(.type == "tool_use") | .tool' \ | sort | uniq -c | sort -rn ``` Это печатает гистограмму вызовов инструментов за весь прогон. Если `shell` наверху со счётом 60, вы нашли свой цикл прежде, чем он нашёл ваш кошелёк — и это однострочник в шаге CI, а не человек, смотрящий на спиннер. --- ## Уровень 6: OctoHub — перехватите каждый upstream-запрос Есть одна вещь, которую ничто из вышеперечисленного показать не может, потому что она происходит ниже агента: **точные байты**, которые Octomind отправил провайдеру, и точные байты, что вернулись. Взгляд агента — это его собственные сообщения. Он не может показать вам запрос на уровне провода — разрешённую модель, полный сериализованный payload, сырой ответ провайдера, реальную задержку. Когда вы подозреваете, что проблема в слое трансляции (системный промпт не тот, что вы думаете; схема инструмента, которую провайдер исковеркал; модель не та, что вы настроили), нужно увидеть провод. [OctoHub](https://github.com/Muvon/octohub) — это наш прокси для LLM, и полное логирование запросов/ответов — смысл его существования. Направьте Octomind на него вместо провайдера, и каждый completion приземлится в базе данных с входом, выходом и метриками. Запустите его: ```bash ./octohub # по умолчанию слушает 127.0.0.1:8080 ``` Он говорит и `POST /v1/completions` (родная форма), и `POST /v1/chat/completions` (классический OpenAI, drop-in для любого OpenAI-совместимого клиента), и оба бьют в один движок и пишут в одну таблицу `completions` с одним и тем же `id` записи. После прогона вытащите сырые записи через admin-API: ```bash curl "http://127.0.0.1:8080/v1/admin/completions?limit=50" \ -H "Authorization: Bearer " ``` Каждая запись несёт ту полную картину, что агент дать не мог: ```json { "id": "cmpl_", "session_id": "", "input_model": "my-model", "resolved_model": "gpt-5.5", "provider": "openai", "usage": { "input_tokens": 10, "output_tokens": 5, "total_tokens": 15, "cost": 0.0001, "request_time_ms": 320 }, "input": [...], "output": [...], "created_at": 1700000000 } ``` `input_model` против `resolved_model` сам по себе ловит целый класс багов «почему оно ведёт себя иначе» — вы запросили одну модель, алиас разрешился в другую. Массивы `input` и `output` — это буквальные payload'ы, так что схема инструмента, которой подавился провайдер, прямо тут, читай. `request_time_ms` — реальная задержка провайдера, отдельно от всего, что добавил Octomind. А `GET /v1/admin/usage` агрегирует всё по API-ключу и временно́му интервалу — так вы переходите от «агент дорогой» к «этот ключ, эта модель, этот час» без гаданий. (Если вы гоняете агентов сразу по нескольким провайдерам, прокси — ещё и то место, где это становится вменяемым — см. [один агент на множестве моделей](/blog/running-one-ai-agent-across-many-models).) Прокси превращает границу модели из непрозрачного края в логируемую, запрашиваемую поверхность. Хранилище по умолчанию — SQLite (`db_url = "sqlite://octohub.db"`, или поставьте `OCTOHUB_DB_URL`), так что никакой инфраструктуры поднимать не надо, прежде чем начать читать запросы. --- ## Когда агент делает X — смотрите в Y Весь смысл — превратить «агент сделал нечто непонятное» в известный поиск. Вот таблица, приклеенная над моим столом: | Симптом | Сначала смотрите | Что ищете | | ------------------------------------------ | -------------------------------------------------- | ----------------------------------------------------- | | Стоимость сессии из ниоткуда | `/info` | `cache rd` ≫ `in` в строке breakdown | | Один промпт стоил всего | `/report` | Единственная строка, несущая счёт | | Окно контекста заполнено / модель «забыла» | блок compression в `/info`, затем `/context large` | Число сжатий и негабаритное сообщение | | Цикл / повторяющиеся вызовы инструментов | колонка tools в `/report`, или `jsonl` + `uniq -c` | Тот же инструмент, те же аргументы, без прогресса | | Инструмент недоступен агенту | `RUST_LOG=octomind::mcp=debug` | Почему кандидат был пропущен | | Результат инструмента выглядит неверно | `/context tool` | Реальные байты, которые получила модель | | Ведёт себя как другая модель | OctoHub `GET /v1/admin/completions` | `input_model` против `resolved_model` | | Ошибка провайдера или странная задержка | `input`/`output` записи OctoHub, `request_time_ms` | Сырой payload и реальный тайминг | | Нужна растяжка в CI | `--format jsonl` | Считать `tool_use`, следить за `cost`, ловить `error` | | Воспроизвести точный прогон | `octomind run --resume ` | Replay из `.jsonl.zst` | --- ## Двухминутная диагностика Вот как прошла бы катастрофа с flaky-тестом, будь это подключено с самого начала, вместо шестиминутной загадки, которой она была на самом деле. Спиннер крутится долго. `/report` — запрос 3 стоит $3,98 и 84 вызова инструментов; другие два в порядке. Значит, дело в этом промпте. `/context tool` — восемьдесят пустых результатов `grep`, модель ни разу не сменила стратегию. Вот цикл, и вот почему. Полное время до корневой причины: секунд девяносто, без четырёх долларов, потому что в настоящем пайплайне гистограмма вызовов инструментов из `jsonl` сработала бы по порогу и убила прогон на двадцатом вызове. Ничего из этого не экзотика. Это тот же инстинкт, что логи, метрики и трассировка в любой системе, которую вы выкатываете в прод, — применённый к системе, чьи сбои молчаливы по природе. Агент не скажет вам, что он потерялся. Но прогон полностью наблюдаем, если спросить его правильно: `/info` для формы, `/report` для виновника, `/context` для рассуждений, лог сессии для записи, `RUST_LOG` для рантайма, `--format jsonl` для машины и OctoHub для провода. Подключите это до дорогого прогона, а не после. — Don --- _[Octomind](https://github.com/Muvon/octomind) и [OctoHub](https://github.com/Muvon/octohub) — открытый исходный код под Apache-2.0. Если нужной вам поверхности для отладки не хватает, [откройте issue](https://github.com/Muvon/octomind/issues) — наблюдаемость из этой статьи во многом существует потому, что наши собственные агенты не переставали нас удивлять._