timdev / stack-logger
A PSR-3 Logger that can track context.
Requires
- php: ~8.0.0 || ~8.1.0 || ~8.2.0
- psr/log: ^1.1
Requires (Dev)
- ergebnis/composer-normalize: ^2.15
- laminas/laminas-log: ^2.12
- laminas/laminas-stdlib: ^3.6.2
- monolog/monolog: ^2.3
- phpunit/phpunit: ^9.5.10
- psalm/plugin-phpunit: ^0.18.0
- squizlabs/php_codesniffer: ^3.6.2
- symfony/console: ^4.4.30
- symfony/process: ^4.4.30
- timdev/devtools: ^0.1.10
- vimeo/psalm: ^5.0
README
Wrap your PSR-3 logger with context accumulation and callable context elements.
Inspiration
Inspired by the similar functionality in pinojs. Design and implementation details differ, but the core idea remains:
Approach
The provided implementation decorates any
implementation of the PSR3 LoggerInterface, providing implementation of the
additional withContext
and addContext
methods defined in this library's
StackLogger interface.
Also provided is MonologStackLogger
, which
decorates a Monolog\Logger
and provides a working withName
implementation.
Usage
Context Stacking
use TimDev\StackLogger\Psr3StackLogger; // can be anything that implements PSR-3 $yourLogger = $container->get(\Psr\Log\LoggerInterface::class); // Decorate it $mainLogger = new Psr3StackLogger($yourLogger); // it works like a regular PSR-3 logger. $mainLogger->info("Hello, World."); // => [2020-10-17 17:40:53] app.INFO: Hello, World. $mainLogger->info("Have some Context", ['my' => 'context']); // => [2020-10-17 17:40:53] app.INFO: Have some Context {"my": "context"} // but you might want to accumulate some context $child1 = $mainLogger->withContext(['child' => 'context']); $child1->info('From a child.', ['call-time' => 'context']); // => [2020-10-17 17:40:53] app.INFO: From a child. {"child":"context","call-time":"context"} // but $mainLogger is still around, without the additional context. $mainLogger->info("Still here, with no accumulated context!"); // => [2020-10-17 17:40:53] app.INFO: Still here, with no accumulated context!
This can be useful in any situation where want to carry some context through successive calls.
/** * Imagine this is a long method that logs a bunch of stuff. */ function complexProcessing(User $user, \TimDev\StackLogger\StackLogger $logger){ $logger = $logger->withContext(['user-id' => $user->id]); $logger->info("Begin processing"); // => [2020-10-17 17:40:53] app.INFO: Begin processing. { "user-id": 123 } foreach($user->getMemberships() as $membership){ $l = $logger->withContext(['membership_id'=>$membership->id]); $l->info("Checking membership"); // => [2020-10-17 17:40:53] app.INFO: Checking membership. { "user-id": 123, 'membership-id' => 1001 } if ($membership->isExpired()){ $l->info('Membership is expired, stopping early.', ['expired-at' => $membership->expiredAt]); // => [2020-10-17 17:40:53] app.INFO: Membership is expired, stopping early. { "user-id": 123, "membership-id" => 1001, "expired-at": "2020-06-30T12:00:00Z' } continue; } // ... $l->info('Done handling membership'); // => [2020-10-17 17:40:53] app.INFO: Done handling membership { "user-id": 123, 'membership-id' => 1001 } } $logger->info("Finished processing user."); // => [2020-10-17 17:40:53] app.INFO: Finished processing user. { "user-id": 123 } }
Dynamic (Callable) Context
The other feature provided here is callable context. Any context elements that
are callable
will be invoked at logging-time, and the result of the
computation will be logged. Callables take a single array argument:
function(array $context): mixed
$startTime = microtime(true); $logger = $logger->withContext([ 'elapsed_ms' => fn() => (microtime(true) - $startTime) * 1000000 * 1000, 'context_count' => fn($ctx) => count($ctx) ]); // ... later that day ... $logger->info('Something happened later.'); // => [2020-10-17 17:40:53] app.INFO: Something happened later. { "elapsed_ms": 1523, "context_count": 2 }
NOTE: you should carefully consider the performance implications when using callables in your stacked context. Context is processed before invoking the wrapped logger's methods. The callables will be invoked on every logging method call, even if the underlying logger is configured to ignore the log-level.
NullLoggers
All StackLogger
implementations provide a static getNullLogger()
method,
which returns an instance that is configured to discard all log messages. These
"null loggers" can be handy in tests, or as a default logger in classes that
can optionally accept a real logger:
use TimDev\StackLogger\MonologStackLogger; class SomeService { public function __construct(?MonologStackLogger $logger = null) { $this->logger = $logger ?? MonologStackLogger::getNullLogger(); } }
To Do
- Make MonologStackLogger implement Monolog's ResettableInterface?
- Consider how this might play with Laravel, the insanely popular PHP framework that I do my best to avoid. 😜
- Track what's going on with PSR-3 v2/v3 as well as monolog and
laminas-log. Eventually, we should rely on the updated + better-typed
versions of the spec. We may need to drop the laminas-log test code since laminas-log will likely always require psr/log@1.1.x