Прологировать чужой код

Вы пришли в проект, которого не писали. Сорок тысяч строк, десяток слоёв, и вопрос ровно один: что здесь на самом деле исполняется?

Читать исходник дорого, и он отвечает не на тот вопрос. По исходнику видно, что может случиться. Прогон отвечает, что случилось: какие функции звались, с какими доводами, что вернули, какие бросили исключение и какие не вернулись вовсе. Регулярно выясняется, что живых путей три, а остальное не исполнялось ни разу — и три четверти чтения были не нужны.

Ниже — что делать по шагам. Всё показанное — вывод настоящих прогонов.

Шаг 0. Не портить чужое дерево

Обмазка переписывает исходник на месте. В чужом проекте это надо решить заранее, а не после. Два способа:

Своя ветка в системе контроля версий — обмазали, прогнали, выбросили ветку. Проще всего, если проект уже под контролем версий.

Черновик инструмента — если контроля версий нет или трогать дерево нельзя:

ouroboros create /srv/tmp/разбор

{"ok": true, "base": "/srv/tmp/разбор", "draft": "/srv/tmp/разбор/черновик", "clean": "/srv/tmp/разбор/чистовик"}

Путь любой ваш; внутри инструмент сам заводит черновик/ с историей изменений и готовит место под чистовик/. Дальше файлы кладут в черновик через ouroboros write, а запускают через ouroboros execute. Оригинал остаётся нетронутым.

Шаг 1. Выбрать, что обмазывать

Это главный шаг, и здесь ошибаются чаще всего.

команда	что обмазывает	когда брать
wrap-file	весь файл целиком	файл небольшой и не горячий
wrap-functions	только названные функции	всегда, когда файл большой или горячий

Обмазывать всё подряд нельзя. На файле с миллионом вызовов в секунду wrap-file топит нужные записи в шуме: полезное есть, но найти его в потоке невозможно. Кроме того, каждый вызов — это две записи на диск, и на горячем пути это заметно.

ouroboros wrap-functions parser.c parse_header parse_body

{"ok": true, "path": "parser.c", "language": "c", "functions_requested": ["parse_body", "parse_header"], "functions_wrapped": 2, "runtime_header": "ouroboros_runtime.h"}

Сверяйте functions_requested с functions_wrapped: если назвали три имени, а обмазалось два, одно имя в файле не нашлось.

Как выбрать функции, если проект чужой: возьмите входную точку и один-два слоя под ней, прогоните, посмотрите, кого позвали, — и обмажьте следующий слой. Дешевле два прогона по десять функций, чем один по тысяче.

Для C и C++ выбирать помогает сам инструмент: ouroboros doc-symbols <файл> покажет, что в файле определено, ouroboros callers <файл> <имя> — кто эту функцию зовёт. Обеим нужен clangd на машине.

Посчитайте объём, прежде чем пугаться. Запись — это две строки JSON на вызов. В прогоне из README семь вызовов дали 14 строк и 1887 байт — около 270 байт на вызов при коротких доводах. Сто тысяч вызовов — примерно 27 МБ. Ваше число будет другим: длина зависит от того, насколько длинные у вас доводы и результаты (и те и другие обрезаются на 200 знаках). Померьте на малом прогоне и умножьте.

Шаг 2. Обмазать

ouroboros wrap-file stats.py

{"ok": true, "path": "stats.py", "language": "python", "functions_wrapped": 3, "runtime_header": "ouroboros_runtime.py"}

Исходник при этом не перепечатывается: разборщик используется только для того, чтобы найти границы функций, а дальше в исходный текст вставляются короткие куски. Отступы, комментарии, пустые строки и стиль остаются как были.

Код, который не разбирается, не сохраняется:

[python] corrupted source in bad.py: invalid syntax (<unknown>, line 1)

Полуобмазанного состояния не бывает.

Шаг 3. Прогнать как обычно

Той же командой, которой проект запускается всегда:

python3 stats.py

Ничего не останавливается, никто не ждёт человека, точек останова нет. Файл записей появится рядом — debug.info; чтобы положить его в другое место, задайте OUROBOROS_DEBUG_INFO.

Гоняйте на настоящей нагрузке. Записи фиксируют то, что случилось; на выдуманных трёх запросах случится ровно то, что вы выдумали, и живые пути так не найдутся.

Шаг 4. Прочитать

Начните со сводки — она отвечает «что вообще живое»:

ouroboros trace-stats debug.info

  "by_function": [
    { "name": "parse_line", "count": 3, "result": 3, "raised": 0, "unknown": 0,
      "duration_seconds": { "min": 1e-06, "max": 2e-06, "mean": 2e-06, "total": 5e-06, "count": 3 } },
    { "name": "average",    "count": 2, "result": 1, "raised": 1, "unknown": 0,
      "duration_seconds": { "min": 2e-06, "max": 3e-06, "mean": 2e-06, "total": 5e-06, "count": 2 } },
    { "name": "report",     "count": 2, "result": 1, "raised": 1, "unknown": 0,
      "duration_seconds": { "min": 6.8e-05, "max": 0.000346, "mean": 0.000207, "total": 0.000414, "count": 2 } }
  ],
  "by_thread": [
    { "thread": "2864987.129949101195776", "count": 7, "functions": 3, "cpus": [] }
  ],
  "timespan": {
    "first": "2026-08-28T23:39:45.166", "last": "2026-08-28T23:39:45.166",
    "seconds": 0.0, "timestamps_parsed": 7, "timestamps_unparsed": 0
  }

Здесь сразу видно: average звали дважды, и один раз он бросил. Дальше — подробности этого вызова:

ouroboros trace debug.info --outcome raised

    {
      "index": 5,
      "started": "2026-08-28T23:39:45.166",
      "call_id": "ef71eb89-6727-4cdf-a3b7-2ea54cff81e3",
      "name": "average",
      "args": "[]",
      "kwargs": "",
      "outcome_kind": "raised",
      "outcome": "ZeroDivisionError: division by zero",
      "duration": 3e-06,
      "cpu": null,
      "thread": "2864987.129949101195776"
    }

args: "[]" — вот чего нет в отслеживании стека. Стек говорит, где сломалось; запись говорит, с чем позвали.

Что читать в записях

Кто живой. Список функций в by_function — это список того, что исполняется. Всё остальное в файле либо мертво, либо не задето вашей нагрузкой; разницу между этими двумя случаями записи не покажут.

С чем зовут. Настоящие доводы, а не те, что в примерах из README проекта. Здесь обычно и обнаруживается, что параметр, объявленный необязательным, всегда приходит заполненным.

Доводы снимаются при входе, до тела. Функция, которая портит собственные входные данные, всё равно записала то, с чем её позвали. Проверено:

def mutate(items):
    items.append(99)
    return len(items)

{"p":"in", …,"fn":"mutate","a":"[1, 2]","k":""}
{"p":"out", …,"fn":"mutate","r":"3","d":1e-06}

Записано [1, 2] — то, с чем позвали, — при том что вернулось 3, то есть длина уже изменённого списка.

Имён доводов в записи нет ни у одного из восьми языков. В поле a везде одни значения:

язык	поле a (по позиции)	поле k (именованные)
Python	только значения: 'мир', [1, 2]	greeting='здравствуй', loud=True
JavaScript	только значения: 2, 3	пусто
C	только значения: 2, 3	пусто
C++	только значения: 2, 3	пусто
Elixir	только значения: 2, 3	пусто
Go	только значения: 2, 3	пусто

Имя позиционного довода из записи не восстановить нигде — смотрите подпись функции в исходнике: поле fn называет функцию, а её подпись лежит рядом в файле. У C, C++, Elixir и Go подпись при обмазке разобрана и имена известны, но их намеренно не пишут: иначе поле a значило бы у одних языков одно, а у других другое, и сверить запись одного языка с записью другого стало бы нельзя. Подробнее — Языки.

Что вернули и что бросили. r и x взаимоисключаются. Отобрать брошенное — --outcome raised.

Кто не вернулся. Строка входа, у которой нет парной строки выхода с тем же id, значит, что вызов вошёл и не вернулся: зависание, падение или жёсткий выход. Вычислять ничего не надо — такие вызовы лежат в поле in_flight каждого ответа. Так находится место, где программа висит, и это же отличает «висит» от «работает медленно».

Кто медленный. --min-duration 0.1 оставит только вызовы дольше 0,1 секунды.

Кто с кем одновременно. th — метка потока, ci — номер ядра. По ним видно, какой поток что делал; без них две переплетённые последовательности вызовов выглядят одной бессмысленной. --thread <метка> оставит один поток.

В обычной программе поле ci равно -1 у всех восьми языков, а в разборе — null. У Python так потому, что функции os.sched_getcpu в CPython нет вовсе, и помощник честно пишет «неизвестно» (ouroboros/runtime.py:75); у остальных — потому, что переносимого способа узнать ядро в их средах нет. Настоящий номер ядра бывает только в сборке C внутри ядра операционной системы. Метка потока th есть везде и всегда состоит из двух частей — процесс и поток; разбор по языкам — в Языках.

Что запускалось. ouroboros execute дописывает в тот же файл по строке на команду:

{"p":"exec","cmd":["python3","stats.py"],"rc":0,"out":"20.0\n","err":""}

Так debug.info остаётся единственным местом, где написано, что запускалось и чем кончилось. Читалка такие строки пропускает и в счёт испорченных не заносит.

Длительность — не цена. Поле d меряет обмазанный прогон. Читать d как стоимость обычного прогона нельзя, и профилировщик она не заменяет. Отсчёт d начинается после записи строки входа, то есть стоимость самой этой записи в d не входит — но всё прочее, что добавила обмазка, входит (ouroboros/runtime.py:311).

Повторить вызов, на котором сломалось

Запись содержит функцию и её доводы. Значит вызов, на котором всё рассыпалось, можно вынуть и повторить у себя — сколько угодно раз, не воспроизводя всю обстановку. Это ровно то, чего не хватает, когда вчерашняя ошибка сегодня не воспроизводится.

Вынимать и подставлять придётся руками: команды «проиграть вызов заново» у инструмента нет.

Работает тем лучше, чем меньше в языке скрытого состояния. В языке без изменяемых переменных функция плюс доводы и есть полное состояние вызова. В языках с изменяемым состоянием придётся восстанавливать ещё и его.

Если нужен снимок «было так»

Тот же прогон годится как снимок поведения до правки. Прогнали до, прогнали после, сравнили записи — ответ получается не «тесты красные», а вот эти сорок вызовов теперь ведут себя иначе, с доводами и результатами обеих сторон.

Отдельной команды «сличить два прогона» у инструмента нет: есть trace, дальше обычные средства сравнения файлов.

Сравнивая, помните про поля, которые меняются от прогона к прогону сами по себе: t, id, d, а также ci и th. Их при сличении обнуляют — иначе разными окажутся все записи до одной.

Убрать за собой

Обмазка не снимается сама. Обратной команды у инструмента нет, и finish её тоже не снимает — он переносит наружу ровно то, что лежит в черновике, минус .git и debug.info.

Убирают её так же, как любую другую правку: git checkout по затронутым файлам, либо выбросив ветку, либо удалив черновик. Не забудьте ouroboros_runtime.py (или .h, .js, .hpp, .ex, .go) — он лежит рядом с обмазанным файлом.

Чего записи не ответят

Что код должен делать. Они говорят, что он делает.

Правильно ли это. Ошибка, работавшая годами, выглядит в записях точно так же, как правильное поведение.

Что происходит в ветке, куда не зашли. Записей не будет, и предупреждения тоже не будет.

Намерение. Функция вернула -1 — код ошибки или настоящий ответ? В записи этого нет.

Полностью — Границы.