Examples, with the real output of every command

Every block on this page is the output of an actual run on an actual machine, taken by site/examples/capture.py and re-taken whenever the tool changes. Nothing here is typed by hand or tidied up afterwards. The programs are short on purpose; the mechanism is the same at any size.

The file after wrapping

This is the shop program from the front page, after ouroboros wrap-file shop.py, in full:

site/examples/shop.py, after

"""What one order costs: goods, the regular-customer discount, delivery."""
from ouroboros_runtime import log as _ouro_log

import sys

PRICES = {"tea": 18.00, "mug": 12.50, "kettle": 21.50}


@_ouro_log
def subtotal(order):
    return sum(PRICES[name] for name in order)


@_ouro_log
def discount(amount):
    """Regular customers get 10% off."""
    return round(amount * 0.10, 2)


@_ouro_log
def delivery(amount):
    """Delivery is free from 50.00."""
    return 0.00 if amount >= 50.00 else 5.00


@_ouro_log
def total(order):
    goods = subtotal(order)
    goods = goods - discount(goods)
    return round(goods + delivery(goods), 2)


if __name__ == "__main__":
    print(f"Total: {total(sys.argv[1:]):.2f}")

Compare it to the file before. What changed:

one import line at the top;
one line, @_ouro_log, above each of the four functions;
nothing else. Same line count inside the bodies, same comments, same docstrings, same order.

Two details of that placement are not decoration. The import goes below the module docstring, because a string put above it stops being the docstring and becomes an ordinary expression — silently. In JavaScript the same import goes below "use strict", because that directive only works while it is first; when it stops being first the program keeps running, with different rules. Both of those were bugs here once, and both are now held down by tests. The beginning of a file is not neutral ground, and most of what can go wrong with this tool goes wrong there.

The decorator sits closest to def — inside any other decorators — so what gets recorded is the function itself, not a wrapper around it.

What each field means

A call writes two lines. The keys are short because a long trace is a big file.

key	on which line	what it is
`p`	both	Phase: `in` when the call is entered, `out` when it comes back.
`t`	`in`	When it was entered. Local time, milliseconds.
`id`	both	A unique id for this one call. It is what joins the two lines.
`fn`	both	The function's name, qualified the way that language qualifies names.
`a`	`in`	The positional arguments, as text, snapshotted on entry — so a function that modifies its own arguments still shows what it was handed.
`k`	`in`	The named arguments, as `name=value`. Languages without them write `""`.
`r`	`out`	What it returned. Never present together with `x`.
`x`	`out`	What it threw: `Type: message`. Never present together with `r`.
`d`	`out`	How long the call took, in seconds, off a monotonic clock.
`th`	`in`	Which process and thread it ran on. The second half is that language's own token — an OS thread, a goroutine, a BEAM process.
`ci`	`in`	Which CPU core. Always `-1`, meaning unknown, in every one of the eight — see limits.

Two consequences of that table are worth stating plainly.

An in with no matching out is a call that never came back — a hang, a crash, a hard exit. That is a design decision rather than an accident: a single line written at completion could not record a call that never completes. ouroboros trace lists them under in_flight.

Argument names are nowhere in the table. a holds values only, in all eight languages. Three of the backends do know the names at wrap time and used to write them, which made the field mean one thing in three languages and another in two, and made cross-language reading impossible. The names are still in your source next to the function; they are genuinely absent from the trace.

The whole schema, with the reasoning behind each decision, is SPEC.md.

Reading a trace

ouroboros trace parses the file and answers with something plainer than the raw lines. ouroboros trace-stats answers with one row per function instead — how often it was called, how it ended, and the real durations:

the first two functions of the four

{
  "ok": true,
  "path": "debug.info",
  "calls_parsed": 4,
  "malformed": 0,
  "total_calls": 4,
  "in_flight": [],
  "by_function": [
    {
      "name": "delivery",
      "count": 1,
      "result": 1,
      "raised": 0,
      "unknown": 0,
      "duration_seconds": {
        "min": 1e-06,
        "max": 1e-06,
        "mean": 1e-06,
        "total": 1e-06,
        "count": 1
      }
    },
    {
      "name": "discount",
      "count": 1,
      "result": 1,
      "raised": 0,
      "unknown": 0,
      "duration_seconds": {
        "min": 3e-06,
        "max": 3e-06,
        "mean": 3e-06,
        "total": 3e-06,
        "count": 1
      }
    },
    {
      "name": "subtotal",
      "count": 1,
      "result": 1,
      "raised": 0,
      "unknown": 0,
      "duration_seconds": {
        "min": 3e-06,
        "max": 3e-06,
        "mean": 3e-06,
        "total": 3e-06,
        "count": 1
      }
    },
    {
      "name": "total",
      "count": 1,
      "result": 1,
      "raised": 0,
      "unknown": 0,
      "duration_seconds": {
        "min": 0.000252,
        "max": 0.000252,
        "mean": 0.000252,
        "total": 0.000252,
        "count": 1
      }
    }
  ],
  "by_thread": [
    {
      "thread": "4102424.138269349349248",
      "count": 4,
      "functions": 4,
      "cpus": []
    }
  ],
  "duration_seconds": {
    "min": 1e-06,
    "max": 0.000252,
    "mean": 6.5e-05,
    "total": 0.000259,
    "count": 4
  },
  "timespan": {
    "first": "2026-09-08T15:50:09.581",
    "last": "2026-09-08T15:50:09.581",
    "seconds": 0.0,
    "timestamps_parsed": 4,
    "timestamps_unparsed": 0
  },
  "note": "counts/durations are over completed calls; `duration_seconds` are REAL per-call durations (exit−entry) from each call's `d`. `by_thread` groups calls by the `th` token (CPUs each thread ran on); empty for traces with no thread field. `in_flight` = entered (`p:in`) but never completed. `timespan` is first→last entry time."
}

The filters are the point of having a reader at all. The first five work on both commands:

you want	ask for	on
one function	`--function delivery`	both
calls mentioning a value	`--contains 46.8`	both
only the calls that threw	`--outcome raised`	both
only the slow ones	`--min-duration 0.5`	both
one thread	`--thread 4065334.128322166978432`	both
the last twenty	`--tail 20`	`trace` only

--regex turns --function and --contains into patterns on either command. --limit and --cursor, on trace only, page through a trace too big to answer at once.

A run that crashes

Same program, an order with a typo in it. Without any recording at all, this is what you get:

python3 shop.py tea mugg

Traceback (most recent call last):
  File "/home/you/shop/shop.py", line 34, in <module>
    print(f"Total: {total(sys.argv[1:]):.2f}")
                    ~~~~~^^^^^^^^^^^^^^
  File "/home/you/shop/ouroboros_runtime.py", line 234, in wrapper
    result = fn(*args, **kwargs)
  File "/home/you/shop/shop.py", line 28, in total
    goods = subtotal(order)
  File "/home/you/shop/ouroboros_runtime.py", line 234, in wrapper
    result = fn(*args, **kwargs)
  File "/home/you/shop/shop.py", line 11, in subtotal
    return sum(PRICES[name] for name in order)
  File "/home/you/shop/shop.py", line 11, in <genexpr>
    return sum(PRICES[name] for name in order)
               ~~~~~~^^^^^^
KeyError: 'mugg'

That names the line, which is useful and often enough. What it does not say is which values got there — and in a real system the bad value is usually born several calls above the line that finally chokes on it.

The trace does say. Filtered to just the calls that ended badly:

ouroboros trace debug.info --outcome raised

{
  "ok": true,
  "path": "debug.info",
  "calls_parsed": 2,
  "malformed": 0,
  "matched": 2,
  "returned": 2,
  "next_cursor": null,
  "in_flight": [],
  "in_flight_truncated": false,
  "records": [
    {
      "index": 0,
      "started": "2026-09-08T15:50:10.553",
      "call_id": "229b19a9-8e37-4565-9447-6770c55e74b6",
      "name": "subtotal",
      "args": "['tea', 'mugg']",
      "kwargs": "",
      "outcome_kind": "raised",
      "outcome": "KeyError: 'mugg'",
      "duration": 4e-06,
      "cpu": null,
      "thread": "4102464.130760939022208"
    },
    {
      "index": 1,
      "started": "2026-09-08T15:50:10.552",
      "call_id": "eae93c75-b5ae-4e9a-9e1e-5643958b50a2",
      "name": "total",
      "args": "['tea', 'mugg']",
      "kwargs": "",
      "outcome_kind": "raised",
      "outcome": "KeyError: 'mugg'",
      "duration": 0.000115,
      "cpu": null,
      "thread": "4102464.130760939022208"
    }
  ]
}

Two calls, not one: subtotal raised KeyError: 'mugg', and so did total, which was inside it. Both records carry the arguments they were handed, so the bad value is visible at the point it entered the program rather than at the point it detonated.

Notice also that the stack trace above now has frames from the helper (ouroboros_runtime.py, line 234) between yours. That is one of the things wrapping always changes, and it is listed as such on the limits page.

The same call on eight languages

One function, add(2, 3), returning 5. Written eight times, in eight languages, compiled or interpreted by eight different toolchains — and recorded into the same shape. These eight blocks came out of one run of capture.py, which uses the project's own cross-language test helpers, so they are eight halves of one measurement rather than eight anecdotes.

Python

{"p":"in","t":"2026-09-08T15:50:11.186","id":"4b394991-8721-4cdb-bcaf-fbac0fdc4f92","ci":-1,"th":"4102502.133342617835392","fn":"add","a":"2, 3","k":""}
{"p":"out","id":"4b394991-8721-4cdb-bcaf-fbac0fdc4f92","fn":"add","r":"5","d":1e-06}

JavaScript

{"p":"in","t":"2026-09-08T15:50:11.296","id":"e82bd76d-7755-472f-94d2-56d0de7328b5","ci":-1,"th":"4102514.0","fn":"add","a":"2, 3","k":""}
{"p":"out","id":"e82bd76d-7755-472f-94d2-56d0de7328b5","fn":"add","r":"5","d":0.000049}

{"p":"in","t":"2026-09-08T15:50:11.410","id":"329d3609-786b-42a9-bc1e-b2e2173423d8","ci":-1,"th":"4102539.4102539","fn":"add","a":"2, 3","k":""}
{"p":"out","id":"329d3609-786b-42a9-bc1e-b2e2173423d8","fn":"add","r":"5","d":0.000000}

C++

{"p":"in","t":"2026-09-08T15:50:12.106","id":"ac004e49-4d7f-4e54-983c-bd22a7b06ac9","ci":-1,"th":"4102565.137414044510080","fn":"add","a":"2, 3","k":""}
{"p":"out","id":"ac004e49-4d7f-4e54-983c-bd22a7b06ac9","fn":"add","r":"5","d":0.000001}

Elixir

{"p":"in","t":"2026-09-08T15:50:13.992","id":"a74c5eee-3544-4dec-8a6d-16f5e4ceb09f","ci":-1,"th":"4103168.#PID<0.95.0>","fn":"add","a":"2, 3","k":""}
{"p":"out","id":"a74c5eee-3544-4dec-8a6d-16f5e4ceb09f","fn":"add","r":"5","d":0.000011}

{"p":"in","t":"2026-09-08T15:50:14.612","id":"32ea753d-0877-48cd-b646-7adb8a3c1cf4","ci":-1,"th":"4104319.1","fn":"add","a":"2, 3","k":""}
{"p":"out","id":"32ea753d-0877-48cd-b646-7adb8a3c1cf4","fn":"add","r":"5","d":0.000001}

Java

{"p":"in","t":"2026-09-08T15:50:15.737","id":"10fb4399-a6c5-48f7-984b-9f8555e44be8","ci":-1,"th":"4104749.3","fn":"Prog.add","a":"2, 3","k":""}
{"p":"out","id":"10fb4399-a6c5-48f7-984b-9f8555e44be8","fn":"Prog.add","r":"5","d":0.000006}

{"p":"in","t":"2026-09-08T15:50:17.879","id":"9402c372-d8ab-4425-b9b9-b62561237971","ci":-1,"th":"4105161.1","fn":"Prog.add","a":"2, 3","k":""}
{"p":"out","id":"9402c372-d8ab-4425-b9b9-b62561237971","fn":"Prog.add","r":"5","d":0.000254}

What is identical, and what is deliberately not

Identical, in all eight: the keys, their order, their meaning, two lines per call, a as 2, 3 — values without names — and ci as -1.

Different, on purpose:

The qualified name. add in Python, C, JavaScript, Go and Elixir; Prog.add in Java and C#, because a method there lives in a class. C++ writes Class::method for a method. Elixir writes the bare name even though the function is in a module.
The thread token. A thread id in Python and C, a worker number in JavaScript (0 for the main one), a goroutine number in Go, a JVM thread in Java, a managed thread in C#, and a BEAM process — #PID<0.95.0> — in Elixir.
How numbers print. Python writes 2e-06, JavaScript writes 0.00005, C writes 0.000000, for durations of the same order. That is each language's own rendering of a number, not different units.

The rule the project holds itself to is: pin the schema, not the dialect. A cross-language test parses two traces, removes the dialect fields, and compares what is left field by field.

Wrapping less than a whole file

wrap-file instruments everything in the file. Two narrower commands exist, and both matter more than they sound:

ouroboros wrap-functions app.py parse_row load_config

Only the functions you name. This is the right tool for a hot path, and the only sane tool for recursion: the Python decorator adds a stack frame per call, so deep recursion that fitted before wrapping may not fit after — wrap the callers, not the recursive function itself. The numbers are on the limits page.

ouroboros wrap-snippet --language python < snippet.py

Reads code on standard input and writes the instrumented version to standard output, touching no files at all. Useful for looking at what the tool would do before letting it do it.

Driving it from an AI agent

The same three steps — instrument, run, read — are exposed over MCP as 17 tools, so a coding agent can check what its own code did instead of predicting it. There is a sandbox mode as well: create_project makes a draft copy, write_file instruments on save, execute runs a command inside the draft with the trace file already pointed at, and finish copies the result back out.

Two things about finish are worth knowing before you use it, and both are in limits: the instrumentation comes back out with your code — the answer says so in as many words — and files that look machine-made are left behind, which includes an image your own program drew. Every skipped file is named, with its reason. Read that list.

Setup for Claude Code and Cursor is on the install page, and the tools themselves are listed in docs/mcp-tools.md — a page that is itself printed from a real conversation with the server rather than written.