diff --git a/.gitignore b/.gitignore index 7c932886..873b8934 100644 --- a/.gitignore +++ b/.gitignore @@ -6,6 +6,7 @@ composer.phar .phpunit.result.cache .phpunit.cache/ +log/* vendor/ .idea/ .php-cs-fixer.cache diff --git a/classes/NanoBaseTest.class.php b/classes/NanoBaseTest.class.php index 731508a1..7169a750 100644 --- a/classes/NanoBaseTest.class.php +++ b/classes/NanoBaseTest.class.php @@ -4,6 +4,8 @@ use PHPUnit\Framework\TestCase; use PHPUnit\Framework\MockObject\MockObject; +use Monolog\LogRecord; +use Monolog\Handler\SyslogHandler; /** * Base class for PHPUnit-based unit tests @@ -69,3 +71,16 @@ protected function setNanoAppMock(NanoObject $obj, MockObject $mock) $reflection_property->setValue($obj, $mock); } } + + +/** + * No-op logging handler. Keeps track of LogRecords sent to it. + */ +class TestLoggingHandler extends SyslogHandler +{ + public ?LogRecord $lastRecord = null; + protected function write(LogRecord $record): void + { + $this->lastRecord = $record; + } +} diff --git a/classes/NanoScript.class.php b/classes/NanoScript.class.php index b73b9071..58dea924 100644 --- a/classes/NanoScript.class.php +++ b/classes/NanoScript.class.php @@ -11,11 +11,12 @@ abstract class NanoScript extends NanoObject { const LOGFILE = 'debug'; - private $isDebug = false; - private $arguments = []; + private bool $isDebug = false; + private array $arguments = []; /** * @param NanoApp $app + * @throws Throwable */ public function __construct(NanoApp $app) { @@ -24,17 +25,14 @@ public function __construct(NanoApp $app) $this->arguments = $argv; $this->isDebug = (bool) getenv('DEBUG'); - parent::__construct(); if ($this->isInDebugMode()) { - $this->debug->log(); - $this->debug->log('Running in debug mode'); - $this->debug->log(); + $this->logger->debug('Running in debug mode'); } - $this->logger->pushProcessor(function ($record) { - $record['extra']['script_class'] = get_class($this); + $this->logger->pushProcessor(function (\Monolog\LogRecord $record) { + $record->extra['script_class'] = get_class($this); return $record; }); @@ -42,15 +40,17 @@ public function __construct(NanoApp $app) try { $this->init(); - } catch (Exception $e) { - $this->logger->error(__METHOD__ . ' failed', [ + } catch (Throwable $e) { + $this->logger->error(get_class($this) . '::init() failed', [ 'exception' => $e, ]); + + throw $e; } } /** - * Setup the script + * Set up the script */ protected function init() { @@ -62,11 +62,27 @@ protected function init() abstract public function run(); /** - * Called when the script execution is completed + * Runs the script (by calling the run method), but wraps the call in the exceptions handling code. * - * @param NanoApp $app + * @throws Throwable + */ + final public function runAndCatch(): mixed + { + try { + return $this->run(); + } catch(Throwable $e) { + $message = get_class($this) . '::run() failed'; + $this->logger->error($message, ['exception' => $e]); + + echo "{$message}:\n{$e->getMessage()}\n\n{$e->getTraceAsString()}\n"; + throw $e; + } + } + + /** + * Called when the script execution is completed */ - public function onTearDown(NanoApp $app) + public function onTearDown(NanoApp $app): void { $this->logger->info('Script completed', [ 'time' => $app->getResponse()->getResponseTime() * 1000, // [ms] @@ -80,18 +96,15 @@ public function onTearDown(NanoApp $app) * * @return bool is script run in debug mode? */ - protected function isInDebugMode() + protected function isInDebugMode(): bool { return $this->isDebug; } /** * Was given option passed in command line as "--option"? - * - * @param string $opt - * @return bool */ - protected function hasOption($opt) + protected function hasOption(string $opt): bool { $opt = sprintf('--%s', $opt); return in_array($opt, $this->arguments); diff --git a/classes/database/DatabaseMysql.class.php b/classes/database/DatabaseMysql.class.php index 2403bbc9..e26c4e9f 100644 --- a/classes/database/DatabaseMysql.class.php +++ b/classes/database/DatabaseMysql.class.php @@ -80,8 +80,8 @@ protected function doConnect() if ($res) { // add more information to Monolog logs - $this->logger->pushProcessor(function ($record) use ($hostInfo) { - $record['extra']['database'] = [ + $this->logger->pushProcessor(function (\Monolog\LogRecord $record) use ($hostInfo) { + $record->extra['database'] = [ 'host' => $hostInfo, 'name' => $this->name, ]; diff --git a/log/.gitkeep b/log/.gitkeep new file mode 100644 index 00000000..e69de29b diff --git a/phpunit.xml b/phpunit.xml index 95c01459..02a5755b 100644 --- a/phpunit.xml +++ b/phpunit.xml @@ -1,6 +1,6 @@ - + diff --git a/tests/NanoLoggerTest.php b/tests/NanoLoggerTest.php index b0571183..ec137619 100644 --- a/tests/NanoLoggerTest.php +++ b/tests/NanoLoggerTest.php @@ -4,24 +4,12 @@ use Monolog\LogRecord; use Nano\Logger\NanoLogger; -/** - * No-op logging handler. Keeps track of LogRecords sent to it. - */ -class TestLoggingHandler extends Monolog\Handler\SyslogHandler -{ - public ?LogRecord $lastRecord = null; - protected function write(LogRecord $record): void - { - $this->lastRecord = $record; - } -} - class NanoLoggerTest extends \Nano\NanoBaseTest { public function testGetLogger(): void { // register a global logging handler for easier testing - $handler = new TestLoggingHandler(ident: 'foo'); + $handler = new Nano\TestLoggingHandler(ident: 'foo'); NanoLogger::pushHandler($handler); $logger = NanoLogger::getLogger(name: __CLASS__, extraFields: ['foo'=>'bar']); diff --git a/tests/NanoScriptTest.php b/tests/NanoScriptTest.php new file mode 100644 index 00000000..6eb5ecb5 --- /dev/null +++ b/tests/NanoScriptTest.php @@ -0,0 +1,125 @@ +foo); + } + + public function run() + { + } +} + +class WorkingTestScript extends FailingTestScript +{ + public static ?Throwable $throw = null; + + protected function init(): int + { + return 0; + } + + /** + * @return int + * @throws Throwable + */ + public function run(): int + { + if (self::$throw) { + throw self::$throw; + } + + $this->logger->info('Hi!'); + return 42; + } +} + +class NanoScriptTest extends \Nano\NanoBaseTest +{ + public function setUp(): void + { + WorkingTestScript::$throw = null; + } + + public function testFailingTestScriptInitException() + { + // register a global logging handler for easier testing + $handler = new Nano\TestLoggingHandler(ident: 'foo'); + NanoLogger::pushHandler($handler); + + try { + Nano::script(__DIR__ . '/..', FailingTestScript::class); + } catch (Throwable) { + } + + // our init method failed, there should be a log message about it + $this->assertInstanceOf(\Monolog\LogRecord::class, $handler->lastRecord); + $this->assertEquals(\Monolog\Level::Error, $handler->lastRecord->level); + + $this->assertEquals('FailingTestScript::init() failed', $handler->lastRecord->message); + $this->assertInstanceOf(TypeError::class, $handler->lastRecord->context['exception']); + } + + /** + * @throws Throwable + */ + public function testWorkingTestScript() + { + $instance = Nano::script(__DIR__ . '/..', WorkingTestScript::class); + $this->assertInstanceOf(WorkingTestScript::class, $instance); + $this->assertEquals(42, $instance->run()); + + // make the run() method throw an exception + $ex = new Exception('foo'); + WorkingTestScript::$throw = $ex; + $this->expectExceptionObject($ex); + $instance->run(); + } + + public function testWorkingTestScriptRunAndCatchException() + { + // make the run() method throw an exception + $ex = new Exception('foo'); + WorkingTestScript::$throw = $ex; + + // register a global logging handler for easier testing + $handler = new Nano\TestLoggingHandler(ident: 'foo'); + NanoLogger::pushHandler($handler); + + try { + Nano::script(__DIR__ . '/..', WorkingTestScript::class)->runAndCatch(); + } catch(Throwable $e) { + $this->assertEquals($ex->getMessage(), $e->getMessage()); + } + + // assert the logging + $this->assertEquals('WorkingTestScript::run() failed', $handler->lastRecord->message); + $this->assertEquals(Monolog\Level::Error, $handler->lastRecord->level); + $this->assertEquals($ex->getMessage(), $handler->lastRecord->context['exception']['message']); + } + + /** + * @throws Throwable + */ + public function testWorkingTestScriptRunAndCatchReturnsTheValue() + { + // register a global logging handler for easier testing + $handler = new Nano\TestLoggingHandler(ident: 'foo'); + NanoLogger::pushHandler($handler); + + $ret = Nano::script(__DIR__ . '/..', WorkingTestScript::class)->runAndCatch(); + $this->assertEquals(42, $ret); + + // assert the logging + $this->assertEquals('Hi!', $handler->lastRecord->message); + $this->assertEquals(Monolog\Level::Info, $handler->lastRecord->level); + $this->assertEquals(WorkingTestScript::class, $handler->lastRecord->extra['script_class']); + } +}