From c471706a5cdf5ec9e5ac155b8ca5fa5501190836 Mon Sep 17 00:00:00 2001 From: Philipp Holzer Date: Mon, 4 Mar 2019 23:39:14 +0100 Subject: [PATCH 1/3] Adding Logger Tests --- src/Util/Logger/StreamLogger.php | 1 - src/Util/Logger/SyslogLogger.php | 16 +- tests/src/Util/Logger/AbstractLoggerTest.php | 143 ++++++++++++++++++ tests/src/Util/Logger/LoggerDataTrait.php | 52 +++++++ tests/src/Util/Logger/ProfilerLoggerTest.php | 58 +++++++ tests/src/Util/Logger/StreamLoggerTest.php | 129 +++++++--------- tests/src/Util/Logger/SyslogLoggerTest.php | 62 ++++++++ tests/src/Util/Logger/SyslogLoggerWrapper.php | 37 +++++ tests/src/Util/Logger/VoidLoggerTest.php | 31 ++++ 9 files changed, 447 insertions(+), 82 deletions(-) create mode 100644 tests/src/Util/Logger/AbstractLoggerTest.php create mode 100644 tests/src/Util/Logger/LoggerDataTrait.php create mode 100644 tests/src/Util/Logger/ProfilerLoggerTest.php create mode 100644 tests/src/Util/Logger/SyslogLoggerTest.php create mode 100644 tests/src/Util/Logger/SyslogLoggerWrapper.php create mode 100644 tests/src/Util/Logger/VoidLoggerTest.php diff --git a/src/Util/Logger/StreamLogger.php b/src/Util/Logger/StreamLogger.php index 7e52df80f1..701d36d2b3 100644 --- a/src/Util/Logger/StreamLogger.php +++ b/src/Util/Logger/StreamLogger.php @@ -115,7 +115,6 @@ class StreamLogger extends AbstractLogger $this->checkStream(); - $this->stream = fopen($this->url, 'a'); $formattedLog = $this->formatLog($level, $message, $context); fwrite($this->stream, $formattedLog); } diff --git a/src/Util/Logger/SyslogLogger.php b/src/Util/Logger/SyslogLogger.php index e21e953ac9..b1abd5bd5e 100644 --- a/src/Util/Logger/SyslogLogger.php +++ b/src/Util/Logger/SyslogLogger.php @@ -4,7 +4,6 @@ namespace Friendica\Util\Logger; use Friendica\Network\HTTPException\InternalServerErrorException; use Friendica\Util\Introspection; -use Psr\Log\InvalidArgumentException; use Psr\Log\LogLevel; /** @@ -117,7 +116,7 @@ class SyslogLogger extends AbstractLogger public function mapLevelToPriority($level) { if (!array_key_exists($level, $this->logLevels)) { - throw new InvalidArgumentException('LogLevel \'' . $level . '\' isn\'t valid.'); + throw new \InvalidArgumentException(sprintf('The level "%s" is not valid.', $level)); } return $this->logLevels[$level]; @@ -146,7 +145,7 @@ class SyslogLogger extends AbstractLogger throw new InternalServerErrorException('Can\'t open syslog for ident "' . $this->channel . '" and facility "' . $this->logFacility . '""'); } - syslog($priority, $message); + $this->syslogWrapper($priority, $message); } /** @@ -172,4 +171,15 @@ class SyslogLogger extends AbstractLogger return $logMessage; } + + /** + * A syslog wrapper to make syslog functionality testable + * + * @param int $level The syslog priority + * @param string $entry The message to send to the syslog function + */ + protected function syslogWrapper($level, $entry) + { + syslog($level, $entry); + } } diff --git a/tests/src/Util/Logger/AbstractLoggerTest.php b/tests/src/Util/Logger/AbstractLoggerTest.php new file mode 100644 index 0000000000..e0c0335837 --- /dev/null +++ b/tests/src/Util/Logger/AbstractLoggerTest.php @@ -0,0 +1,143 @@ +introspection = \Mockery::mock(Introspection::class); + $this->introspection->shouldReceive('getRecord')->andReturn([ + 'file' => self::FILE, + 'line' => self::LINE, + 'function' => self::FUNC + ]); + } + + public function assertLogline($string) + { + $this->assertRegExp(self::LOGLINE, $string); + } + + public function assertLoglineNums($assertNum, $string) + { + $this->assertEquals($assertNum, preg_match_all(self::LOGLINE, $string)); + } + + /** + * Test if the logger works correctly + */ + public function testNormal() + { + $logger = $this->getInstance(); + $logger->emergency('working!'); + $logger->alert('working too!'); + $logger->debug('and now?'); + $logger->notice('message', ['an' => 'context']); + + $text = $this->getContent(); + $this->assertLogline($text); + $this->assertLoglineNums(4, $text); + } + + /** + * Test if a log entry is correctly interpolated + */ + public function testPsrInterpolate() + { + $logger = $this->getInstance(); + + $logger->emergency('A {psr} test', ['psr' => 'working']); + $logger->alert('An {array} test', ['array' => ['it', 'is', 'working']]); + $text = $this->getContent(); + $this->assertContains('A working test', $text); + $this->assertContains('An ["it","is","working"] test', $text); + } + + /** + * Test if a log entry contains all necessary information + */ + public function testContainsInformation() + { + $logger = $this->getInstance(); + $logger->emergency('A test'); + + $text = $this->getContent(); + $this->assertContains('"file":"' . self::FILE . '"', $text); + $this->assertContains('"line":' . self::LINE, $text); + $this->assertContains('"function":"' . self::FUNC . '"', $text); + } + + /** + * Test if the minimum level is working + */ + public function testMinimumLevel() + { + $logger = $this->getInstance(LogLevel::NOTICE); + + $logger->emergency('working'); + $logger->alert('working'); + $logger->error('working'); + $logger->warning('working'); + $logger->notice('working'); + $logger->info('not working'); + $logger->debug('not working'); + + $text = $this->getContent(); + + $this->assertLoglineNums(5, $text); + } + + /** + * Test with different logging data + * @dataProvider dataTests + */ + public function testDifferentTypes($function, $message, array $context) + { + $logger = $this->getInstance(); + $logger->$function($message, $context); + + $text = $this->getContent(); + + $this->assertLogline($text); + + $this->assertContains(@json_encode($context), $text); + } +} diff --git a/tests/src/Util/Logger/LoggerDataTrait.php b/tests/src/Util/Logger/LoggerDataTrait.php new file mode 100644 index 0000000000..1267098a88 --- /dev/null +++ b/tests/src/Util/Logger/LoggerDataTrait.php @@ -0,0 +1,52 @@ + [ + 'function' => 'emergency', + 'message' => 'test', + 'context' => ['a' => 'context'], + ], + 'alert' => [ + 'function' => 'alert', + 'message' => 'test {test}', + 'context' => ['a' => 'context', 2 => 'so', 'test' => 'works'], + ], + 'critical' => [ + 'function' => 'critical', + 'message' => 'test crit 2345', + 'context' => ['a' => 'context', 'wit' => ['more', 'array']], + ], + 'error' => [ + 'function' => 'error', + 'message' => 2.554, + 'context' => [], + ], + 'warning' => [ + 'function' => 'warning', + 'message' => 'test warn', + 'context' => ['a' => 'context'], + ], + 'notice' => [ + 'function' => 'notice', + 'message' => 2346, + 'context' => ['a' => 'context'], + ], + 'info' => [ + 'function' => 'info', + 'message' => null, + 'context' => ['a' => 'context'], + ], + 'debug' => [ + 'function' => 'debug', + 'message' => true, + 'context' => ['a' => false], + ], + ]; + } +} diff --git a/tests/src/Util/Logger/ProfilerLoggerTest.php b/tests/src/Util/Logger/ProfilerLoggerTest.php new file mode 100644 index 0000000000..848191a4d6 --- /dev/null +++ b/tests/src/Util/Logger/ProfilerLoggerTest.php @@ -0,0 +1,58 @@ +logger = \Mockery::mock(LoggerInterface::class); + $this->profiler = \Mockery::mock(Profiler::class); + } + + /** + * Test if the profiler is profiling data + * @dataProvider dataTests + */ + public function testProfiling($function, $message, array $context) + { + $logger = new ProfilerLogger($this->logger, $this->profiler); + + $this->logger->shouldReceive($function)->with($message, $context)->once(); + $this->profiler->shouldReceive('saveTimestamp')->with(\Mockery::any(), 'file', \Mockery::any())->once(); + $logger->$function($message, $context); + } + + /** + * Test the log() function + */ + public function testProfilingLog() + { + $logger = new ProfilerLogger($this->logger, $this->profiler); + + $this->logger->shouldReceive('log')->with(LogLevel::WARNING, 'test', ['a' => 'context'])->once(); + $this->profiler->shouldReceive('saveTimestamp')->with(\Mockery::any(), 'file', \Mockery::any())->once(); + + $logger->log(LogLevel::WARNING, 'test', ['a' => 'context']); + } +} diff --git a/tests/src/Util/Logger/StreamLoggerTest.php b/tests/src/Util/Logger/StreamLoggerTest.php index 38706231ce..bbf94419a6 100644 --- a/tests/src/Util/Logger/StreamLoggerTest.php +++ b/tests/src/Util/Logger/StreamLoggerTest.php @@ -2,126 +2,89 @@ namespace Friendica\Test\src\Util\Logger; -use Friendica\Test\MockedTest; use Friendica\Test\Util\VFSTrait; -use Friendica\Util\Introspection; use Friendica\Util\Logger\StreamLogger; -use Mockery\MockInterface; use org\bovigo\vfs\vfsStream; +use org\bovigo\vfs\vfsStreamFile; use Psr\Log\LogLevel; -class StreamLoggerTest extends MockedTest +class StreamLoggerTest extends AbstractLoggerTest { - const LOGLINE = '/\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2} .* \[.*\]: .* \{.*\"file\":\".*\".*,.*\"line\":\d*,.*\"function\":\".*\".*,.*\"uid\":\".*\".*,.*\"process_id\":\d*.*\}/'; - - const FILE = 'test'; - const LINE = 666; - const FUNC = 'myfunction'; - use VFSTrait; /** - * @var Introspection|MockInterface + * @var StreamLogger */ - private $introspection; + private $logger; + + /** + * @var vfsStreamFile + */ + private $logfile; protected function setUp() { parent::setUp(); $this->setUpVfsDir(); - - $this->introspection = \Mockery::mock(Introspection::class); - $this->introspection->shouldReceive('getRecord')->andReturn([ - 'file' => self::FILE, - 'line' => self::LINE, - 'function' => self::FUNC - ]); - } - - public function assertLogline($string) - { - $this->assertRegExp(self::LOGLINE, $string); - } - - public function assertLoglineNums($assertNum, $string) - { - $this->assertEquals($assertNum, preg_match_all(self::LOGLINE, $string)); - } - - public function testNormal() - { - $logfile = vfsStream::newFile('friendica.log') - ->at($this->root); - - $logger = new StreamLogger('test', $logfile->url(), $this->introspection); - $logger->emergency('working!'); - $logger->alert('working too!'); - $logger->debug('and now?'); - $logger->notice('message', ['an' => 'context']); - - $text = $logfile->getContent(); - $this->assertLogline($text); - $this->assertLoglineNums(4, $text); } /** - * Test if a log entry is correctly interpolated + * {@@inheritdoc} */ - public function testPsrInterpolate() + protected function getInstance($level = LogLevel::DEBUG) { - $logfile = vfsStream::newFile('friendica.log') + $this->logfile = vfsStream::newFile('friendica.log') ->at($this->root); - $logger = new StreamLogger('test', $logfile->url(), $this->introspection); + $this->logger = new StreamLogger('test', $this->logfile->url(), $this->introspection, $level); - $logger->emergency('A {psr} test', ['psr' => 'working']); - $logger->alert('An {array} test', ['array' => ['it', 'is', 'working']]); - $text = $logfile->getContent(); - $this->assertContains('A working test', $text); - $this->assertContains('An ["it","is","working"] test', $text); + return $this->logger; } /** - * Test if a log entry contains all necessary information + * {@inheritdoc} */ - public function testContainsInformation() + protected function getContent() { - $logfile = vfsStream::newFile('friendica.log') - ->at($this->root); - - $logger = new StreamLogger('test', $logfile->url(), $this->introspection); - - $logger->emergency('A test'); - - $text = $logfile->getContent(); - $this->assertContains('"process_id":' . getmypid(), $text); - $this->assertContains('"file":"' . self::FILE . '"', $text); - $this->assertContains('"line":' . self::LINE, $text); - $this->assertContains('"function":"' . self::FUNC . '"', $text); + return $this->logfile->getContent(); } /** - * Test if the minimum level is working + * Test if a stream is working */ - public function testMinimumLevel() + public function testStream() { $logfile = vfsStream::newFile('friendica.log') ->at($this->root); - $logger = new StreamLogger('test', $logfile->url(), $this->introspection, LogLevel::NOTICE); + $filehandler = fopen($logfile->url(), 'ab'); + $logger = new StreamLogger('test', $filehandler, $this->introspection); $logger->emergency('working'); - $logger->alert('working'); - $logger->error('working'); - $logger->warning('working'); - $logger->notice('working'); - $logger->info('not working'); - $logger->debug('not working'); $text = $logfile->getContent(); - $this->assertLoglineNums(5, $text); + $this->assertLogline($text); + } + + /** + * Test if the close statement is working + */ + public function testClose() + { + $logfile = vfsStream::newFile('friendica.log') + ->at($this->root); + + $logger = new StreamLogger('test', $logfile->url(), $this->introspection); + $logger->emergency('working'); + $logger->close(); + // close doesn't affect + $logger->emergency('working too'); + + $text = $logfile->getContent(); + + $this->assertLoglineNums(2, $text); } /** @@ -187,4 +150,14 @@ class StreamLoggerTest extends MockedTest $logger->log('NOPE', 'a test'); } + + /** + * Test when the file is null + * @expectedException \InvalidArgumentException + * @expectedExceptionMessage A stream must either be a resource or a string. + */ + public function testWrongFile() + { + $logger = new StreamLogger('test', null, $this->introspection); + } } diff --git a/tests/src/Util/Logger/SyslogLoggerTest.php b/tests/src/Util/Logger/SyslogLoggerTest.php new file mode 100644 index 0000000000..545f76b32f --- /dev/null +++ b/tests/src/Util/Logger/SyslogLoggerTest.php @@ -0,0 +1,62 @@ +introspection->shouldReceive('addClasses')->with([SyslogLogger::class]); + } + + /** + * {@inheritdoc} + */ + protected function getContent() + { + return $this->logger->getContent(); + } + + /** + * {@inheritdoc} + */ + protected function getInstance($level = LogLevel::DEBUG) + { + $this->logger = new SyslogLoggerWrapper('test', $this->introspection, $level); + + return $this->logger; + } + + + /** + * Test when the minimum level is not valid + * @expectedException \InvalidArgumentException + * @expectedExceptionMessageRegExp /The level ".*" is not valid./ + */ + public function testWrongMinimumLevel() + { + $logger = new SyslogLoggerWrapper('test', $this->introspection, 'NOPE'); + } + + /** + * Test when the minimum level is not valid + * @expectedException \InvalidArgumentException + * @expectedExceptionMessageRegExp /The level ".*" is not valid./ + */ + public function testWrongLogLevel() + { + $logger = new SyslogLoggerWrapper('test', $this->introspection); + + $logger->log('NOPE', 'a test'); + } +} diff --git a/tests/src/Util/Logger/SyslogLoggerWrapper.php b/tests/src/Util/Logger/SyslogLoggerWrapper.php new file mode 100644 index 0000000000..63ad53690e --- /dev/null +++ b/tests/src/Util/Logger/SyslogLoggerWrapper.php @@ -0,0 +1,37 @@ +content = ''; + } + + /** + * Gets the content from the wrapped Syslog + * + * @return string + */ + public function getContent() + { + return $this->content; + } + + /** + * {@inheritdoc} + */ + protected function syslogWrapper($level, $entry) + { + $this->content .= $entry . PHP_EOL; + } +} diff --git a/tests/src/Util/Logger/VoidLoggerTest.php b/tests/src/Util/Logger/VoidLoggerTest.php new file mode 100644 index 0000000000..4c436d697a --- /dev/null +++ b/tests/src/Util/Logger/VoidLoggerTest.php @@ -0,0 +1,31 @@ +$function($message, $context); + } + + /** + * Test the log() function + */ + public function testProfilingLog() + { + $logger = new VoidLogger(); + $logger->log(LogLevel::WARNING, 'test', ['a' => 'context']); + } +} From 42e9d90066eacdcdfe3d416a18da808d511bbeed Mon Sep 17 00:00:00 2001 From: Philipp Holzer Date: Mon, 4 Mar 2019 23:49:37 +0100 Subject: [PATCH 2/3] Adding Logger Tests --- src/Util/Logger/SyslogLogger.php | 27 ++++++++++++++++--- tests/src/Util/Logger/SyslogLoggerTest.php | 11 ++++++++ tests/src/Util/Logger/SyslogLoggerWrapper.php | 3 +++ 3 files changed, 38 insertions(+), 3 deletions(-) diff --git a/src/Util/Logger/SyslogLogger.php b/src/Util/Logger/SyslogLogger.php index b1abd5bd5e..83c3fc3ce5 100644 --- a/src/Util/Logger/SyslogLogger.php +++ b/src/Util/Logger/SyslogLogger.php @@ -66,6 +66,12 @@ class SyslogLogger extends AbstractLogger */ private $logLevel; + /** + * A error message of the current operation + * @var string + */ + private $errorMessage; + /** * {@inheritdoc} * @param string $level The minimum loglevel at which this logger will be triggered @@ -141,8 +147,12 @@ class SyslogLogger extends AbstractLogger */ private function write($priority, $message) { - if (!openlog(self::IDENT, $this->logOpts, $this->logFacility)) { - throw new InternalServerErrorException('Can\'t open syslog for ident "' . $this->channel . '" and facility "' . $this->logFacility . '""'); + set_error_handler([$this, 'customErrorHandler']); + $opened = openlog(self::IDENT, $this->logOpts, $this->logFacility); + restore_error_handler(); + + if (!$opened) { + throw new \UnexpectedValueException(sprintf('Can\'t open syslog for ident "%s" and facility "%s": ' . $this->errorMessage, $this->channel, $this->logFacility)); } $this->syslogWrapper($priority, $message); @@ -172,6 +182,11 @@ class SyslogLogger extends AbstractLogger return $logMessage; } + private function customErrorHandler($code, $msg) + { + $this->errorMessage = preg_replace('{^(fopen|mkdir)\(.*?\): }', '', $msg); + } + /** * A syslog wrapper to make syslog functionality testable * @@ -180,6 +195,12 @@ class SyslogLogger extends AbstractLogger */ protected function syslogWrapper($level, $entry) { - syslog($level, $entry); + set_error_handler([$this, 'customErrorHandler']); + $written = syslog($level, $entry); + restore_error_handler(); + + if (!$written) { + throw new \UnexpectedValueException(sprintf('Can\'t write into syslog for ident "%s" and facility "%s": ' . $this->errorMessage, $this->channel, $this->logFacility)); + } } } diff --git a/tests/src/Util/Logger/SyslogLoggerTest.php b/tests/src/Util/Logger/SyslogLoggerTest.php index 545f76b32f..fbd691d5eb 100644 --- a/tests/src/Util/Logger/SyslogLoggerTest.php +++ b/tests/src/Util/Logger/SyslogLoggerTest.php @@ -59,4 +59,15 @@ class SyslogLoggerTest extends AbstractLoggerTest $logger->log('NOPE', 'a test'); } + + /** + * Test when the logfacility is wrong (string) + * @expectedException \UnexpectedValueException + * @expectedExceptionMessageRegExp /Can\'t open syslog for ident ".*" and facility ".*": .* / + */ + public function testServerException() + { + $logger = new SyslogLoggerWrapper('test', $this->introspection, LogLevel::DEBUG, null, 'a string'); + $logger->emergency('not working'); + } } diff --git a/tests/src/Util/Logger/SyslogLoggerWrapper.php b/tests/src/Util/Logger/SyslogLoggerWrapper.php index 63ad53690e..779067e28e 100644 --- a/tests/src/Util/Logger/SyslogLoggerWrapper.php +++ b/tests/src/Util/Logger/SyslogLoggerWrapper.php @@ -6,6 +6,9 @@ use Friendica\Util\Introspection; use Friendica\Util\Logger\SyslogLogger; use Psr\Log\LogLevel; +/** + * Wraps the SyslogLogger for replacing the syslog call with a string field. + */ class SyslogLoggerWrapper extends SyslogLogger { private $content; From 0ac3b7091ca76b9bb66eb1abe522e6aae8d8f0c5 Mon Sep 17 00:00:00 2001 From: Philipp Holzer Date: Tue, 5 Mar 2019 00:11:02 +0100 Subject: [PATCH 3/3] Added close test --- tests/src/Util/Logger/SyslogLoggerTest.php | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/tests/src/Util/Logger/SyslogLoggerTest.php b/tests/src/Util/Logger/SyslogLoggerTest.php index fbd691d5eb..aee94e7fdf 100644 --- a/tests/src/Util/Logger/SyslogLoggerTest.php +++ b/tests/src/Util/Logger/SyslogLoggerTest.php @@ -70,4 +70,16 @@ class SyslogLoggerTest extends AbstractLoggerTest $logger = new SyslogLoggerWrapper('test', $this->introspection, LogLevel::DEBUG, null, 'a string'); $logger->emergency('not working'); } + + /** + * Test the close() method + */ + public function testClose() + { + $logger = new SyslogLoggerWrapper('test', $this->introspection); + $logger->emergency('test'); + $logger->close(); + // Reopened itself + $logger->emergency('test'); + } }