Debugging

pop-debug watches an application while it runs and writes down what it saw. A Debugger holds one or more handlers — each tracking one aspect of the request — and one storage object they all write to. It answers the questions a stack trace does not: how long did that take, how much memory did it use, what queries actually ran.

composer require popphp/pop-debug

Setting up the Debugger#

Three pieces: a Pop\Debug\Debugger, at least one handler, and a storage object.

use Pop\Debug\Debugger;
use Pop\Debug\Handler\MessageHandler;
use Pop\Debug\Storage\File;

$debugger = new Debugger();
$debugger->addHandler(new MessageHandler());
$debugger->setStorage(new File(__DIR__ . '/../var/debug'));

$debugger['message']->addMessage('Hey! Something happened!');

$debugger->save();

Handlers and storage can go into the constructor instead, individually or as one array:

use Pop\Debug\Debugger;
use Pop\Debug\Handler\MessageHandler;
use Pop\Debug\Handler\TimeHandler;
use Pop\Debug\Storage\File;

$debugger = new Debugger(new MessageHandler(), new File(__DIR__ . '/../var/debug'));

$other = new Debugger([new TimeHandler(), new MessageHandler(), new File(__DIR__ . '/../var/debug')]);

A handler is reachable on the debugger by array offset. The key is the class name, lowercased with Handler stripped: MessageHandler is message, QueryHandler is query. Pass a name to a handler's constructor to register more than one of a type, and that name is prefixed onto the key:

use Pop\Debug\Debugger;
use Pop\Debug\Handler\MessageHandler;

$debugger = new Debugger();
$debugger->addHandler(new MessageHandler('requests'));
$debugger->addHandler(new MessageHandler('background-jobs'));

$debugger['requests-message']->addMessage('Handled an inbound request');
$debugger['background-jobs-message']->addMessage('Ran a queued job');

save() writes every handler's output and returns the debugger's request ID — a hex string shared by everything that debugger records, so one request's events can be correlated afterward. setRequestId() overrides it with a trace ID your middleware already assigned.

Handlers#

Seven handlers ship, all extending Pop\Debug\Handler\AbstractHandler, which is also the base to extend for one of your own.

TimeHandler needs nothing beyond being registered — it starts when constructed and stops when the debugger saves. MemoryHandler samples on demand, so you call it at the points worth comparing:

use Pop\Debug\Debugger;
use Pop\Debug\Handler\MemoryHandler;
use Pop\Debug\Handler\TimeHandler;
use Pop\Debug\Storage\File;

$debugger = new Debugger();
$debugger->addHandler(new TimeHandler());
$debugger->addHandler(new MemoryHandler());
$debugger->setStorage(new File(__DIR__ . '/../var/debug'));

$debugger['memory']->updateMemoryUsage();
$debugger['memory']->updatePeakMemoryUsage();

$debugger->save();

ExceptionHandler takes exceptions you catch and hand it, rather than installing itself as a global handler:

use Pop\Debug\Debugger;
use Pop\Debug\Handler\ExceptionHandler;
use Pop\Debug\Storage\File;

$debugger = new Debugger(new ExceptionHandler(), new File(__DIR__ . '/../var/debug'));

try {
    throw new \Exception('Error: This is a test exception');
} catch (\Exception $e) {
    $debugger['exception']->addException($e);
    $debugger->save();
}

QueryHandler is the one that ties into another component. pop-db's adapters accept a listener, and handing listen() the handler's class name gives you back a configured instance to register:

use Pop\Db\Db;
use Pop\Db\Record;
use Pop\Debug\Debugger;
use Pop\Debug\Handler\QueryHandler;
use Pop\Debug\Storage\File;

class DebugUser extends Record {}

$db = Db::connect('sqlite', ['database' => __DIR__ . '/../var/app.sqlite']);
DebugUser::setDb($db);

$debugger = new Debugger();
$debugger->addHandler($db->listen(QueryHandler::class));
$debugger->setStorage(new File(__DIR__ . '/../var/debug', 'ndjson'));

$user = new DebugUser(['username' => 'admin']);
$user->save();

$debugger->save();

Each query is recorded with its SQL, its elapsed time and its bound parameters.

The query handler records bound values verbatim, so keep debug storage out of production or filter what you record.

RequestHandler's redaction is per instance and adjustable in three ways:

use Pop\Debug\Handler\RequestHandler;

$requestHandler = new RequestHandler();

$requestHandler->setRedactSensitiveData(false);        // off — captures raw values
$requestHandler->setRedactedKeys(['password', 'pin']); // replaces the default key list
$requestHandler->addRedactedKey('x-internal-id');      // adds to the current list

Storage#

There are two storage adapters, Pop\Debug\Storage\File and Pop\Debug\Storage\Database, both extending Pop\Debug\Storage\AbstractStorage. That's the whole list — there's no HTTP storage and no log storage, whatever else a debugger can be wired to.

File writes one file per handler into a directory, named for the request ID and the handler key. CSV is the default; TSV and NDJSON are the alternatives, chosen with the second constructor argument:

use Pop\Debug\Debugger;
use Pop\Debug\Handler\MessageHandler;
use Pop\Debug\Storage\File;

$debugger = new Debugger(new MessageHandler(), new File(__DIR__ . '/../var/debug', 'ndjson'));

$debugger['message']->addMessage('Hey! Something happened!');

$debugger->save();

The CSV output is one flat row per event:

key,handler,start,end,elapsed,type,message,context
b7aba38cac741e612f47418d230aabd3,message,1787584513.9951,,,message,Hey! Something happened!,

NDJSON writes the same fields as one JSON object per line, keeping context as real nested JSON rather than a json_encode()d string in a flat cell — which makes it the right choice for jq or a log aggregator, and for the query and PHP handlers, whose context is deeply nested.

The directory has to exist and be writable before you construct the adapter. A missing one throws Pop\Debug\Storage\Exception ("Error: That directory does not exist.") from the constructor, so a bad path fails at wiring time.

Database takes a pop-db adapter and an optional table name, defaulting to pop_debug, and creates the table with its indexes on construction if it is not already there:

use Pop\Db\Db;
use Pop\Debug\Debugger;
use Pop\Debug\Handler\MessageHandler;
use Pop\Debug\Storage\Database;

$db = Db::connect('sqlite', ['database' => __DIR__ . '/../var/debug.sqlite']);

$debugger = new Debugger(new MessageHandler(), new Database($db, 'my_debug_table'));

$debugger['message']->addMessage('to the database');

$debugger->save();

The columns are id, key, handler, start, end, elapsed, type, message and context — the same fields the file adapters write, with context stored as JSON text.

clear() empties the whole store: on File it removes every file directly inside the storage directory, so give the debugger a directory of its own.

Logging#

Logging is not a third storage adapter. It's a separate channel: addLogger() hands debug events to any PSR-3 logger as they happen, and it runs alongside whatever storage is set — or, in principle, instead of it.

use Pop\Debug\Debugger;
use Pop\Debug\Handler\ExceptionHandler;
use Pop\Debug\Storage\File;
use Pop\Log\Logger;
use Pop\Log\Writer\File as LogFile;

$debugger = new Debugger();
$debugger->addHandler(new ExceptionHandler(true));
$debugger->setStorage(new File(__DIR__ . '/../var/debug'));

$debugger->addLogger(new Logger(new LogFile(__DIR__ . '/../var/log/debug.log')), [
    'level'   => Logger::ERROR,
    'context' => 'json',
]);

try {
    throw new \Pop\Debug\Exception('This is a test debug exception');
} catch (\Exception $e) {
    $debugger['exception']->addException($e);
    $debugger->save();
}

The second argument is the logging parameters. level is the only one every handler requires — the PSR-3 level entries are written at. context set to json attaches the handler's own data as the entry's context; how that renders is the log writer's business, and a plain-text Pop\Log\Writer\File flattens it rather than emitting JSON.

Two more parameters turn logging into an alert rather than a transcript. On the memory handler, usage_limit and peak_limit are byte counts, logged only when a sample goes above them. On the query, request and time handlers, limit is a number of seconds, logged only when the operation took longer:

use Pop\Debug\Debugger;
use Pop\Debug\Handler\TimeHandler;
use Pop\Debug\Storage\File;
use Pop\Log\Logger;
use Pop\Log\Writer\File as LogFile;

$debugger = new Debugger();
$debugger->addHandler(new TimeHandler());
$debugger->setStorage(new File(__DIR__ . '/../var/debug'));

$debugger->addLogger(new Logger(new LogFile(__DIR__ . '/../var/log/slow.log')), [
    'level' => Logger::WARNING,
    'limit' => 1,
]);

$debugger->save();

A request that runs past a second logs a line naming the limit and the actual elapsed time; one that does not logs nothing at all.

pop-log's Logger is what usually goes in here, so where the entries land is the writer's business — a file, syslog, a database table, stdout — and the debugger does not care which.

Custom handlers, the full logging parameter set and the storage adapters' own read methods go past what this page covers — see the pop-debug README.

See Also#

• Logging — the Pop\Log\Logger and writers this page hands events to
• Error Handling — catching the exceptions the exception handler records
• Profiler — the queries the query handler is watching go past
• Auditing — a durable record of changes, as opposed to a snapshot of one request
• pop-debug README — every handler and its options