Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: Check logs against parts of the message only #6704

Merged
merged 2 commits into from
Oct 20, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
17 changes: 15 additions & 2 deletions system/Test/CIUnitTestCase.php
Original file line number Diff line number Diff line change
Expand Up @@ -349,8 +349,6 @@ protected function mockSession()
* @param string|null $expectedMessage
*
* @return bool
*
* @throws Exception
*/
public function assertLogged(string $level, $expectedMessage = null)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is not related to this PR, but why $expectedMessage can be null?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not sure either.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🤦‍♂️

{
Expand All @@ -365,6 +363,21 @@ public function assertLogged(string $level, $expectedMessage = null)
return $result;
}

/**
* Asserts that there is a log record that contains `$logMessage` in the message.
*/
public function assertLogContains(string $level, string $logMessage, string $message = ''): void
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

$expectedMessage is better? assertLogged() uses it.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

My understanding is $expectedMessage is used since the assertion compares the message as expected in the logs.
For assertLogContains, I think it is counter-intuitive to use $expectedMessage when it can only be a part of the whole expected message. I was also thinking whether to use $needle or $needleMessage as alternative name.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No preference from me

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I am a little uncomfortable with both $needle and $needleMessage.
needle needs haystack.

So let's leave it as it is.

{
$this->assertTrue(
TestLogger::didLog($level, $logMessage, false),
$message ?: sprintf(
'Failed asserting that logs have a record of message containing "%s" with level "%s".',
$logMessage,
$level
)
);
}

/**
* Hooks into CodeIgniter's Events system to check if a specific
* event was triggered or not.
Expand Down
18 changes: 16 additions & 2 deletions system/Test/TestLogger.php
Original file line number Diff line number Diff line change
Expand Up @@ -59,10 +59,24 @@ public function log($level, $message, array $context = []): bool
*
* @return bool
*/
public static function didLog(string $level, $message)
public static function didLog(string $level, $message, bool $useExactComparison = true)
{
$lowerLevel = strtolower($level);

foreach (self::$op_logs as $log) {
if (strtolower($log['level']) === strtolower($level) && $message === $log['message']) {
if (strtolower($log['level']) !== $lowerLevel) {
continue;
}

if ($useExactComparison) {
if ($log['message'] === $message) {
return true;
}

continue;
}

if (strpos($log['message'], $message) !== false) {
return true;
}
}
Expand Down
6 changes: 6 additions & 0 deletions tests/system/Test/TestCaseTest.php
Original file line number Diff line number Diff line change
Expand Up @@ -45,6 +45,12 @@ public function testLogging()
$this->assertLogged('error', 'Some variable did not contain a value.');
}

public function testAssertLogContains()
{
log_message('error', 'Some variable did not contain a value.');
$this->assertLogContains('error', 'variable did not');
}

public function testEventTriggering()
{
Events::on('foo', static function ($arg) use (&$result) {
Expand Down
71 changes: 71 additions & 0 deletions tests/system/Test/TestLoggerTest.php
Original file line number Diff line number Diff line change
@@ -0,0 +1,71 @@
<?php

/**
* This file is part of CodeIgniter 4 framework.
*
* (c) CodeIgniter Foundation <[email protected]>
*
* For the full copyright and license information, please view
* the LICENSE file that was distributed with this source code.
*/

namespace CodeIgniter\Test;

use Config\Logger;

/**
* @internal
*/
final class TestLoggerTest extends CIUnitTestCase
{
/**
* @dataProvider provideDidLogCases
*/
public function testDidLogMethod(bool $expected, string $level, string $message, bool $exact): void
{
(new TestLogger(new Logger()))->log('error', 'Some variable did not contain a value.');

$this->assertSame(
$expected,
TestLogger::didLog($level, $message, $exact),
);
}

public function provideDidLogCases(): iterable
{
yield 'exact' => [
true,
'error',
'Some variable did not contain a value.',
true,
];

yield 'wrong level' => [
false,
'warning',
'Some variable did not contain a value.',
true,
];

yield 'wrong message' => [
false,
'error',
'Some variables did not contain a value.',
true,
];

yield 'approximate' => [
true,
'error',
'Some variable did not',
false,
];

yield 'approximate but wrong level' => [
false,
'warning',
'Some variable did not',
false,
];
}
}
2 changes: 2 additions & 0 deletions user_guide_src/source/changelogs/v4.3.0.rst
Original file line number Diff line number Diff line change
Expand Up @@ -128,6 +128,8 @@ Testing
- The CITestStreamFilter filter class now implements methods for adding a filter to streams. See :ref:`testing-cli-output`.
- Added the ``PhpStreamWrapper`` to make it easier to work with setting data to ``php://stdin``. See :ref:`testing-cli-input`.
- Added method :ref:`benchmark-timer-record` to measure performance in a callable. Also enhanced common function ``timer()`` to accept optional callable.
- A boolean third parameter ``$useExactComparison`` is added to ``TestLogger::didLog()`` which sets whether log messages are checked verbatim. This defaults to ``true``.
- Added method ``CIUnitTestCase::assertLogContains()`` which compares log messages by parts instead of the whole of the message.

Database
========
Expand Down
7 changes: 6 additions & 1 deletion user_guide_src/source/testing/overview.rst
Original file line number Diff line number Diff line change
Expand Up @@ -126,7 +126,12 @@ Additional Assertions
assertLogged($level, $expectedMessage)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

Ensure that something you expected to be logged actually was:
Ensure that something you expected to be logged was actually logged:

assertLogContains($level, $logMessage)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

Ensure that there's a record in the logs which contains a message part.

.. literalinclude:: overview/007.php

Expand Down
12 changes: 8 additions & 4 deletions user_guide_src/source/testing/overview/007.php
Original file line number Diff line number Diff line change
@@ -1,9 +1,13 @@
<?php

$config = new LoggerConfig();
$logger = new Logger($config);
$config = new Config\Logger();
$logger = new CodeIgniter\Log\Logger($config);

// ... do something that you expect a log entry from
// check verbatim the log message
$logger->log('error', "That's no moon");

$this->assertLogged('error', "That's no moon");

// check that a portion of the message is found in the logs
$exception = new RuntimeException('Hello world.');
$logger->log('error', $exception->getTraceAsString());
$this->assertLogContains('error', '{main}');