Tracing a PHP CLI application with filo

filo is a zero-extension PHP call tracer. No PECL module, no Xdebug session: it registers a file:// stream wrapper and rewrites your code’s AST on the way in, so every function entry and exit gets timed. Your files on disk are never touched: instrumented copies live in a throwaway cache.

This tutorial builds a small CLI app with a realistic call stack, traces it, and then turns the trace into something you can actually read.

Everything below was run against filo v0.2.0 / dev-main on PHP 8.3.6. All numbers and output are real.

1. The demo app

orderbot prints an order report. This is nothing exotic: it has a command, a service, two repositories, a pricing helper, a renderer:

src/
├── Cli/
│   ├── Application.php        run() → dispatch + poor man's container
│   ├── ReportCommand.php      execute()
│   └── TableRenderer.php      render()
├── Service/
│   ├── OrderService.php       report()   ← the interesting one
│   ├── PricingService.php     gross()
│   └── TaxCalculator.php      rateFor()
└── Repository/
    ├── OrderRepository.php    all()
    ├── CustomerRepository.php find()
    └── Database.php           usleep() stands in for query latency

The call chain is five levels deep: Application::run → ReportCommand::execute → OrderService::report → OrderRepository::all → Database::selectOrders. Deep enough that a stack trace tells you nothing useful about where time goes.

You can download the filo tutorial source code for this article here. It is a zip archive, with PHP scripts.

Here is the method the whole tutorial revolves around:

<?php
public function report(): array
{
    $rows = [];

    foreach ($this->orders->all() as $order) {
        $customer = $this->customers->find($order['customer_id']);

        $rows[] = [
            'order'    => $order['id'],
            'customer' => $customer['name'],
            'lines'    => $order['lines'],
            'gross'    => $this->pricing->gross($order),
        ];
    }

    return $rows;
}
?>

At a first glance, it looks fine. And that is the point that Filo tries to fix.

2. Install

composer require --dev giacomomasseron/filo

filo registers bootstrap.php through Composer’s autoload.files, so it executes the instant vendor/autoload.php is loaded — and does nothing at all unless explicitly enabled.

3. The one rule that matters for CLI

The filo feature is not loaded, and neither is anything loaded before vendor/autoload.php.

The stream wrapper can only intercept files that are included after it has been registered. So the entry point must load the autoloader first and everything else second:

#!/usr/bin/env php
<?php

declare(strict_types=1);

// 1. Autoloader first. filo's bootstrap.php runs here and registers the
//    stream wrapper — BEFORE any App class has been loaded.
require __DIR__ . '/../vendor/autoload.php';

// 2. Every App class loaded from here on passes through the wrapper
//    and comes back instrumented.
exit((new App\Cli\Application())->run($argv));
?>

If you define classes directly inside bin/orderbot, or require them above the autoloader, they simply won’t appear in the trace. For full coverage including the entry script, point auto_prepend_file at vendor/giacomomasseron/filo/bootstrap.php.

Second rule, smaller: vendor is excluded by default with FILO_EXCLUDE, so you trace your code, not Composer’s.

4. Turning it on

Two switches. For a one-off CLI run, the env var is the natural one:

For an editor-driven workflow, create an empty .filo-on file in the project root instead. It’s checked per run, so toggling is instant. In a Laravel app, a .env entry does not work, as phpdotenv loads after the tracer bootstraps.

The -d opcache.enable_cli=0 is critical: opcache CLI is off by default, but if you’ve turned it on, cached opcodes bypass the wrapper entirely and you’ll get an empty trace.

Run it. The output is byte-identical to the untraced run. Instrumentation doesn’t change behaviour:

ORDER    CUSTOMER            LINES      GROSS
---------------------------------------------
1001     Aurora Tools BV         3     301.29
1002     Aurora Tools BV         1      48.28
1003     Nordwind GmbH           5     928.80
1004     Nordwind GmbH           2     142.80
1005     Papeterie Lyon          4     492.30
1006     Papeterie Lyon          1      18.00

But now there’s a trace next to it:

Add .filo/ to .gitignore.

5. What’s in the trace

Format v1 is deliberately small. It is a flat event list, not a nested tree:

{
  "version": 1,
  "duration": 41780000,
  "context": { "sapi": "cli", "argv": ["bin/orderbot", "report"] },
  "events": [
    { "i": 0, "p": -1, "fn": "App\\Cli\\Application::run",
      "file": "/home/you/orderbot/src/Cli/Application.php", "line": 15,
      "s": 149289, "e": 41653573, "m": 3078600 }
  ]
}

• i: event id, p — parent event id (-1 = root)
• s / e: start and end offsets in nanoseconds from process start
• m: memory usage at entry, in bytes
• fn: the __METHOD__ form: App\Repo::find, my_function, {closure}

Worth noting: with CLI, the context object carries sapi and argv, not the method/uri pair the README shows for HTTP requests. If you write your own tooling, you might want to handle both.

The one derived number you actually care about isn’t in the file:

self time = (e - s) − Σ (direct children’s e - s)

Inclusive time tells you a call was slow. Self time tells you it was slow rather than something it called.

6. Displaying it, option A: the built-in viewer

vendor/bin/filo serve        # http://127.0.0.1:8090

This is a single-file, zero-dependency viewer on PHP’s built-in server: trace list, zoomable flamegraph, call tree with self-times, top-functions table, and a live panel for paused requests. CLI traces land in the same list as web ones. It is verified against the run above:

 curl -s http://127.0.0.1:8090/api/traces | head -c 200
[{"version":1,"ts":"2026-09-14T09:03:00+00:00","duration":41666870,
  "context":{"sapi":"cli","argv":["bin/orderbot","report"]}, ...

It’s localhost-only by design, as it is supposed to be used by developers or local AI. And, for security reasons, traces contain file paths and variable values, so never expose that port.

Three JSON endpoints back it: /api/traces, /api/breaks, /api/breakpoints. If you want a nicer UI, drop static files into server/ui/ (entry point index.html) and they’re served instead of the built-in page, no code changes needed.

7. Displaying it, option B: in the terminal

For a CLI app, staying in the terminal is often the faster loop, and it makes the trace format concrete. tools/trace-report.php, which is included alongside this tutorial, reads the newest trace and prints a call tree plus a hotspot table. It’s ~150 lines and the only real logic is the self-time subtraction from §5.

php tools/trace-report.php                  # newest trace
php tools/trace-report.php path/to.json     # a specific one

Here is a real output from the run above, abridged in the middle. Of course, your mileage may vary, but it should stay very similar:

filo  bin/orderbot report
41.78 ms · 31 calls · sapi cli · 20260914-090557-df3af8ef.json

CALL TREE   (inclusive | self)
App\Cli\Application::run    41.58 ms |    0.01 ms self
 ├─ App\Cli\Application::makeReportCommand     0.36 ms |    0.36 ms self
 └─ App\Cli\ReportCommand::execute    41.21 ms |    0.01 ms self
    ├─ App\Service\OrderService::report    41.17 ms |    0.04 ms self
    │  ├─ App\Repository\OrderRepository::all     4.17 ms |    0.07 ms self
    │  │  └─ App\Repository\Database::selectOrders     4.10 ms |    4.10 ms self
    │  ├─ App\Repository\CustomerRepository::find     6.11 ms |    0.01 ms self
    │  │  └─ App\Repository\Database::selectCustomer   6.11 ms |    6.11 ms self
    │  ├─ App\Service\PricingService::gross     0.00 ms |    0.00 ms self
    │  │  └─ App\Service\TaxCalculator::rateFor     0.00 ms |    0.00 ms self
    │  ├─ App\Repository\CustomerRepository::find     6.09 ms |    0.00 ms self
    │  │  └─ App\Repository\Database::selectCustomer   6.09 ms |    6.09 ms self
    │           ⋮  (four more identical pairs)
    └─ App\Cli\TableRenderer::render     0.03 ms |    0.03 ms self

TOP FUNCTIONS BY SELF TIME
FUNCTION                                        CALLS     SELF ms    SHARE
---------------------------------------------------------------------------
App\Repository\Database::selectCustomer             6       36.90    88.3%  ← N+1?
App\Repository\Database::selectOrders               1        4.10     9.8%
App\Cli\Application::makeReportCommand              1        0.36     0.9%
App\Repository\OrderRepository::all                 1        0.07     0.2%
App\Service\OrderService::report                    1        0.04     0.1%
App\Cli\TableRenderer::render                       1        0.03     0.1%
App\Service\PricingService::gross                   6        0.03     0.1%
App\Repository\CustomerRepository::find             6        0.03     0.1%

Two design choices make this readable, and they’re worth stealing for any trace UI:

Aggregate by self time, not inclusive time. Sorted by inclusive time, the top of the table would be Application::run at 41.58 ms: technically true, completely useless. Sorted by self time, the actual culprit is line one.

Show the call count next to it. CustomerRepository::find costs 0.01 ms per call; nobody would ever optimise it. What matters is the pair high call count × high total self time, which is the signature of an N+1. The script flags it automatically (≥5 calls and ≥10% of runtime), and the repetition in the call tree above is the same finding in visual form.

Note also how the tree exonerates the innocent: OrderService::report has 41.17 ms inclusive but 0.04 ms self. It isn’t slow. It’s calling something slow, six times.

8. Acting on it

The trace says: 6 customer lookups for 6 orders, but only 3 distinct customers. Batch them.

-        $rows = [];
-
-        foreach ($this->orders->all() as $order) {
-            $customer = $this->customers->find($order['customer_id']);
+        $rows   = [];
+        $orders = $this->orders->all();
+
+        // Resolve every customer up front, in one pass.
+        $customers = $this->customers->findMany(array_column($orders, 'customer_id'));
+
+        foreach ($orders as $order) {
+            $customer = $customers[$order['customer_id']];

with findMany() de-duplicating ids before hitting storage. Re-run, re-measure:

43% off the runtime, and the measurement loop was: run the command, run the report script. That’s the useful part of having a tracer wired into a CLI app.

9. Bonus: pausing a CLI run

filo also does function-entry breakpoints, without a daemon, nor a IDE protocol. They work on a CLI process exactly as on a web request:

$ vendor/bin/filo break "App\Service\PricingService::gross"
breakpoint added: App\Service\PricingService::gross

# terminal 1 — the process freezes at that function's entry
$ FILO_ENABLED=1 php -d opcache.enable_cli=0 bin/orderbot report

# terminal 2
$ vendor/bin/filo pending
090547-13d7e9  App\Service\PricingService::gross   bin/orderbot report

$ vendor/bin/filo show 090547-13d7e9
App\Service\PricingService::gross
  at /home/you/orderbot/src/Service/PricingService.php:11
  request: bin/orderbot report
  vars:
{
    "order": {
        "id": 1001,
        "customer_id": 7,
        "lines": 3,
        "net": 249,
        "country": "NL"
    },
    "__this": {
        "__class": "App\\Service\\PricingService",
        "props": { "tax": { "__class": "App\\Service\\TaxCalculator", "props": [] } }
    }
}

$ vendor/bin/filo continue 090547-13d7e9
released 090547-13d7e9

The command then finishes normally and still writes its trace. There are some noteworthy details:

• Entry only. You see arguments and $this as the function begins. No stepping, no eval, as these are deliberately left to Xdebug.
• Once per request. So a breakpoint inside a loop pauses once, not six times.
• Pause time is excluded from trace timings. So inspecting doesn’t corrupt your numbers.
• Auto-continue after FILO_BREAK_TIMEOUT seconds, by default 120, a forgotten breakpoint can’t hang a process forever.
• State lives in .filo/breakpoints.json and .filo/traces/breaks/; the CLI and the web UI read and write the same files, so you can mix them freely.

One practical note from building this: if a paused process is killed rather than continued, its snapshot lingers in pending. vendor/bin/filo continue --all clears the strays.

10. Gotchas worth knowing up front

11. Where to take it next

filo also plugs into test suites, which is the natural home for what section 8 did by hand: it turns the finding into a regression guard:

<?php
// Pest
expect(fn () => $service->report())->toRunUnder(30);              // ms
expect(fn () => $service->report())->toCall('App\Repository\Database::selectCustomer')->atMost(3);

// PHPUnit, via the Filo\Testing\FiloAssertions trait
$this->assertCallCount('App\Repository\Database::selectCustomer', atMost: 3, callable: fn () => $service->report());
?>

toCall() on its own asserts nothing — always finish the chain with atMost() / atLeast() / times(). And if the suite runs without filo enabled, call-based assertions throw FiloNotEnabledException rather than silently passing, which is the right default.

Register Filo\Testing\PHPUnit\TraceExtension in phpunit.xml and every failing test drops a trace artifact in .filo/traces/tests/ — openable in the same viewer, uploadable from CI as a build artifact.

12. Conclusion

filo is a genuinely interesting tool, and the reason is the idea at its core rather than the feature list.

Call tracing in PHP has always been extension territory. You install Xdebug or XHProf or Excimer, you fight your php.ini, and on shared hosting or a locked-down container you simply don’t get to profile at all. filo sidesteps the whole problem by noticing that PHP lets you take over file:// yourself: register a stream wrapper, parse each incoming file with nikic/php-parser, inject entry and exit hooks into the AST, hand the rewritten source back to the engine. The engine never knows. Your files on disk are never touched: the instrumented copies live in a throwaway cache. It is a genuinely creative use of a mundane part of the language, and it’s rare to see a userland trick buy you this much.

What that creates is actual feature. From the run in this tutorial: a full parent-linked call tree with correct self-time accounting, aggregation that surfaced an N+1 three layers down as 88.3% of runtime, a flamegraph viewer, per-test trace artifacts for CI, performance assertions you can commit as regression guards, and, the part I expected to be vapour, working function-entry breakpoints on a live CLI process, complete with arguments and $this, with pause time correctly excluded from the timings so inspecting doesn’t corrupt your numbers. No extension. No daemon. No IDE protocol. Two commands from composer require to a flamegraph.

The rough edges are real, though, and mostly follow from the same design choice. Because instrumentation happens at include time, anything the engine loads another way is invisible: your entry script, anything required above the autoloader, native functions, eval, arrow functions. Because the trick operates on source that opcache has already cached, opcache and filo cannot coexist, and the failure mode on a web SAPI is nasty, since opcache may keep serving instrumented code after you switch tracing off, the file on disk being unchanged. Smaller scrapes show elsewhere: line numbers drift inside instrumented files, a killed process leaves a stale entry in pending until you run continue --all, and the shipped web UI is explicitly a functional placeholder with a documented seam for replacing it. None of these bit me hard, but you do need to know them: see section 3 and section 10.

That’s a fair trade for v0.2.0 on a package with single-digit installs. The architecture is sound, the constraints are honestly documented rather than hidden, and the author has clearly thought about the failure modes: the auto-continue timeout on breakpoints and the FiloNotEnabledException on silently-unenforced assertions are both the kind of detail you only add after being burned. Whether it matures into something you’d reach for over Xdebug depends on questions byeond this tutorial: overhead on a large real codebase, behaviour under frameworks with heavy bootstrapping, and how the viewer develops.

Worth watching, and worth an afternoon on a project where installing an extension isn’t an option. Keep an eye on where filo goes.