diff --git a/doc/02-handlers-formatters-processors.md b/doc/02-handlers-formatters-processors.md index d3d31e043..cd8b397a2 100644 --- a/doc/02-handlers-formatters-processors.md +++ b/doc/02-handlers-formatters-processors.md @@ -136,6 +136,14 @@ receives, up until a configured threshold of number of messages of a certain level is reached, after it will pass all log messages to the wrapped handler. Useful for applying in batch processing when you're only interested in significant failures instead of minor, single erroneous events. +- [_LogMonsterHandler_](https://github.com/Seldaek/monolog/blob/main/src/Monolog/Handler/LogMonsterHandler.php): A dead-man's switch wrapper. It watches + log records go by and expects to be fed at least a given number (`$hunger`) of + them before the process ends. If it stays hungry until `close()` (and was not + manually fed via `feed()`), the monster gets angry and emits a complaint record + at the configured `$angerLevel` to the handler it wraps. This is useful to catch + cron jobs or workers that died before doing their expected work, or to make sure + every code path at least logs some records. Records carrying context can be made + to count as the only "real" food by enabling `$wantsContextChips`. ## Formatters diff --git a/src/Monolog/Handler/LogMonsterHandler.php b/src/Monolog/Handler/LogMonsterHandler.php new file mode 100644 index 000000000..0c78df47b --- /dev/null +++ b/src/Monolog/Handler/LogMonsterHandler.php @@ -0,0 +1,192 @@ + + * + * For the full copyright and license information, please view the LICENSE + * file that was distributed with this source code. + */ + +namespace Monolog\Handler; + +use Closure; +use Monolog\Level; +use Monolog\Logger; +use Monolog\ResettableInterface; +use Monolog\Formatter\FormatterInterface; +use Psr\Log\LogLevel; +use Monolog\LogRecord; + +/** + * Watches log records go by and expects to be fed at least $hunger of them before + * the process ends. If it stays hungry until close() (and was not manually fed()), + * the monster gets angry and emits a complaint record at $angerLevel to the nested + * handler. Useful as a dead-man's switch for cron jobs / workers that should produce + * a known amount of log activity before they finish, or to make sure that every code + * path / request in the application at least logs some amount of records. + * + * Records carrying context are "cookies with chocolate chips" — when $wantsContextChips + * is true, only records with non-empty context count toward feeding the monster. + * + * Thanks to Jonathan Wage for the idea https://x.com/seldaek/status/1491110384023277569 + * + * @author Jordi Boggiano + */ +class LogMonsterHandler extends Handler implements ProcessableHandlerInterface, ResettableInterface, FormattableHandlerInterface +{ + use ProcessableHandlerTrait; + + /** + * Handler or factory Closure($record, $this) + * + * @phpstan-var (Closure(LogRecord|null, HandlerInterface): HandlerInterface)|HandlerInterface + */ + protected Closure|HandlerInterface $handler; + + protected int $hunger; + + protected Level $angerLevel; + + protected string $channel; + + protected bool $wantsContextChips; + + /** Number of records the monster has eaten so far */ + protected int $eaten = 0; + + /** Whether the monster has been manually fed and should stay quiet on close */ + protected bool $fed = false; + + /** + * @phpstan-param (Closure(LogRecord|null, HandlerInterface): HandlerInterface)|HandlerInterface $handler + * + * @param Closure|HandlerInterface $handler Handler or factory Closure($record|null, $logMonsterHandler). + * @param int $hunger Number of log records the monster must eat before close() to stay satisfied. + * @param int|string|Level|LogLevel::* $angerLevel Level at which the monster logs its complaint when it goes hungry. + * @param string $channel Channel name stamped on the synthetic complaint record, note the record only gets sent to the given $handler, and will for example not go to the handlers configured for $channel in Symfony. + * @param bool $wantsContextChips If true, only records carrying context count toward feeding the monster. + * + * @phpstan-param value-of|value-of|Level|LogLevel::* $angerLevel + */ + public function __construct(Closure|HandlerInterface $handler, int $hunger, int|string|Level $angerLevel = Level::Error, string $channel = 'log-monster', bool $wantsContextChips = false) + { + $this->handler = $handler; + $this->hunger = $hunger; + $this->channel = $channel; + $this->wantsContextChips = $wantsContextChips; + $this->angerLevel = Logger::toMonologLevel($angerLevel); + } + + /** + * @inheritDoc + */ + public function isHandling(LogRecord $record): bool + { + return true; + } + + /** + * Manually feed the log monster so it does not complain on close (until reset() is called) + */ + public function feed(): void + { + $this->fed = true; + } + + /** + * @inheritDoc + */ + public function handle(LogRecord $record): bool + { + if (!$this->wantsContextChips || \count($record->context) > 0) { + $this->eaten++; + } + + // the monster only watches records go by, it never consumes them + return false; + } + + /** + * @inheritDoc + */ + public function close(): void + { + if (!$this->fed && $this->eaten < $this->hunger) { + $record = new LogRecord( + datetime: new \DateTimeImmutable('now'), + channel: $this->channel, + level: $this->angerLevel, + message: 'Om nom nom... the log monster is hangry: it only ate '.$this->eaten.' of '.$this->hunger.' expected log records', + context: ['eaten' => $this->eaten, 'hunger' => $this->hunger], + ); + + if (\count($this->processors) > 0) { + $record = $this->processRecord($record); + } + + $this->getHandler($record)->handle($record); + } + + $this->getHandler()->close(); + } + + public function reset(): void + { + $this->fed = false; + $this->eaten = 0; + + $this->resetProcessors(); + + if ($this->getHandler() instanceof ResettableInterface) { + $this->getHandler()->reset(); + } + } + + /** + * Return the nested handler + * + * If the handler was provided as a factory, this will trigger the handler's instantiation. + */ + public function getHandler(?LogRecord $record = null): HandlerInterface + { + if (!$this->handler instanceof HandlerInterface) { + $handler = ($this->handler)($record, $this); + if (!$handler instanceof HandlerInterface) { + throw new \RuntimeException("The factory Closure should return a HandlerInterface"); + } + $this->handler = $handler; + } + + return $this->handler; + } + + /** + * @inheritDoc + */ + public function setFormatter(FormatterInterface $formatter): HandlerInterface + { + $handler = $this->getHandler(); + if ($handler instanceof FormattableHandlerInterface) { + $handler->setFormatter($formatter); + + return $this; + } + + throw new \UnexpectedValueException('The nested handler of type '.\get_class($handler).' does not support formatters.'); + } + + /** + * @inheritDoc + */ + public function getFormatter(): FormatterInterface + { + $handler = $this->getHandler(); + if ($handler instanceof FormattableHandlerInterface) { + return $handler->getFormatter(); + } + + throw new \UnexpectedValueException('The nested handler of type '.\get_class($handler).' does not support formatters.'); + } +} diff --git a/tests/Monolog/Handler/LogMonsterHandlerTest.php b/tests/Monolog/Handler/LogMonsterHandlerTest.php new file mode 100644 index 000000000..80013886d --- /dev/null +++ b/tests/Monolog/Handler/LogMonsterHandlerTest.php @@ -0,0 +1,140 @@ + + * + * For the full copyright and license information, please view the LICENSE + * file that was distributed with this source code. + */ + +namespace Monolog\Handler; + +use Monolog\Level; + +class LogMonsterHandlerTest extends \Monolog\Test\MonologTestCase +{ + /** + * @covers Monolog\Handler\LogMonsterHandler::handle + * @covers Monolog\Handler\LogMonsterHandler::close + */ + public function testWellFedMonsterStaysQuiet() + { + $test = new TestHandler(); + $handler = new LogMonsterHandler($test, 2); + $handler->handle($this->getRecord(Level::Debug)); + $handler->handle($this->getRecord(Level::Info)); + $handler->close(); + + $this->assertCount(0, $test->getRecords()); + } + + /** + * @covers Monolog\Handler\LogMonsterHandler::handle + * @covers Monolog\Handler\LogMonsterHandler::close + */ + public function testHungryMonsterGetsAngryOnClose() + { + $test = new TestHandler(); + $handler = new LogMonsterHandler($test, 3); + $handler->handle($this->getRecord(Level::Info)); + $handler->close(); + + $records = $test->getRecords(); + $this->assertCount(1, $records); + $this->assertSame(Level::Error, $records[0]->level); + $this->assertSame(1, $records[0]->context['eaten']); + $this->assertSame(3, $records[0]->context['hunger']); + } + + /** + * @covers Monolog\Handler\LogMonsterHandler::__construct + * @covers Monolog\Handler\LogMonsterHandler::close + */ + public function testAngerLevelIsConfigurable() + { + $test = new TestHandler(); + $handler = new LogMonsterHandler($test, 1, Level::Critical); + $handler->close(); + + $this->assertTrue($test->hasCriticalRecords()); + } + + /** + * @covers Monolog\Handler\LogMonsterHandler::feed + * @covers Monolog\Handler\LogMonsterHandler::close + */ + public function testManualFeedSilencesTheMonster() + { + $test = new TestHandler(); + $handler = new LogMonsterHandler($test, 5); + $handler->feed(); + $handler->close(); + + $this->assertCount(0, $test->getRecords()); + } + + /** + * @covers Monolog\Handler\LogMonsterHandler::handle + */ + public function testWantsContextChipsIgnoresPlainRecords() + { + $test = new TestHandler(); + $handler = new LogMonsterHandler($test, 1, Level::Error, 'log-monster', wantsContextChips: true); + $handler->handle($this->getRecord(Level::Info)); + $handler->close(); + + // a record without context does not count, so the monster goes hungry + $this->assertTrue($test->hasErrorRecords()); + } + + /** + * @covers Monolog\Handler\LogMonsterHandler::handle + */ + public function testWantsContextChipsIsSatisfiedByRecordsWithContext() + { + $test = new TestHandler(); + $handler = new LogMonsterHandler($test, 1, Level::Error, 'log-monster', wantsContextChips: true); + $handler->handle($this->getRecord(Level::Info, 'test', ['chocolate' => 'chips'])); + $handler->close(); + + $this->assertCount(0, $test->getRecords()); + } + + /** + * @covers Monolog\Handler\LogMonsterHandler::reset + */ + public function testResetReArmsTheMonster() + { + $test = new TestHandler(); + $test->setSkipReset(true); + $handler = new LogMonsterHandler($test, 1); + $handler->handle($this->getRecord(Level::Info)); + $handler->reset(); + $handler->close(); + + // after reset the monster is hungry again and never got fed + $this->assertTrue($test->hasErrorRecords()); + } + + /** + * @covers Monolog\Handler\LogMonsterHandler::close + */ + public function testComplaintUsesConfiguredChannel() + { + $test = new TestHandler(); + $handler = new LogMonsterHandler($test, 1, Level::Error, 'cookie-jar'); + $handler->close(); + + $records = $test->getRecords(); + $this->assertSame('cookie-jar', $records[0]->channel); + } + + public function testIsHandlingAlwaysReturnsTrue() + { + $handler = new LogMonsterHandler(new TestHandler(), 1); + + $this->assertTrue($handler->isHandling($this->getRecord(Level::Debug))); + } +}