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

Introduce logging middleware #4967

Merged
merged 4 commits into from
Nov 21, 2021

Conversation

morozov
Copy link
Member

@morozov morozov commented Nov 7, 2021

Q A
Type improvement
BC Break no

Closes #4941.

This middleware is meant to replace the SQLLogger interface but it's not a drop-in replacement:

  1. It will log the statements and their parameters in the form in which they are passed to the DBAL driver (i.e. with list parameters expanded and named parameters converted to the positional ones).
  2. There is no equivalent of the stopQuery() method. If instrumentation around the query methods is needed, it should be implemented as a separate middleware.

Technical details:

  1. "Connecting" is logged in the driver but "Disconnecting" is logged in the connection. This is a bit asymmetric but there's a reason: the connection parameters in the DBAL format are only available at the driver level but the driver doesn't handle disconnection.
  2. The middleware doesn't log exceptions. The severity of the exception as well as the need to log it should be determined by the component that handles the exception.

Test changes:

  1. The IBM DB2 connection test is removed as it assumes that Connection::getWrappedConnection() will return a driver connection while it may return a middleware (see Deprecate Connection::getWrappedConnection(), mark Connection::connect() internal #4966). The error handling during prepare() cannot always be tested in isolation and is covered in a more reliable way in
    public function testExceptionOnPrepareAndExecute(): void
  2. The assertion in testDeterminesDatabasePlatformWhenConnectingToNonExistentDatabase() is removed since the middleware driver always implements the VersionAwarePlatformDriver, even if the wrapped driver doesn't, so based on that, the wrapper connection will always connect to detect the server version. This will be likely addressed by Remove VersionAwarePlatformDriver and ServerInfoAwareConnection #4764 in 4.0.0. UPD: this entire feature is pointless (Remove VersionAwarePlatformDriver and ServerInfoAwareConnection #4764 (comment)).

TODO:

  • Add tests for the logger middleware.
  • Remove the dependency of ResultCacheTest on DebugStack (Refactor query caching tests #5008).
  • Remove the "Temporarily enable Monolog in the test suite" commit.

@morozov morozov force-pushed the issues/4941-logging-middleware branch 7 times, most recently from 20f3a22 to 61d7adc Compare November 7, 2021 23:47
composer.json Outdated Show resolved Hide resolved
@morozov morozov force-pushed the issues/4941-logging-middleware branch 7 times, most recently from 1754d89 to 52bb036 Compare November 15, 2021 00:23
@morozov morozov force-pushed the issues/4941-logging-middleware branch 7 times, most recently from 69a38c2 to 389dbe5 Compare November 16, 2021 02:23
@morozov morozov marked this pull request as ready for review November 16, 2021 02:25
@derrabus derrabus added this to the 3.2.0 milestone Nov 17, 2021
This case is already covered by `ConnectionTest::testExceptionOnPrepareAndExecute()`
@morozov morozov linked an issue Nov 21, 2021 that may be closed by this pull request
.github/workflows/continuous-integration.yml Show resolved Hide resolved
private function maskPassword(array $params): array
{
if (isset($params['password'])) {
$params['password'] = '******';
Copy link
Member

Choose a reason for hiding this comment

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

One might think we are giving an indication about the number of characters. How about this instead:

Suggested change
$params['password'] = '******';
$params['password'] = '<redacted>';

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 discussed this with my colleague and we came to the same conclusion. Let's change it.

@morozov morozov merged commit 5b456d8 into doctrine:3.2.x Nov 21, 2021
@morozov morozov deleted the issues/4941-logging-middleware branch November 21, 2021 18:46
@derrabus
Copy link
Member

Follow-up: doctrine/DoctrineBundle#1429

@Igor100
Copy link

Igor100 commented Feb 2, 2022

Hello @morozov
How to use this midleware instead the construction:
$doctrine = $this->getDoctrine();
$doctrineConnection = $doctrine->getConnection();
$stack = new \Doctrine\DBAL\Logging\DebugStack();
$doctrineConnection->getConfiguration()->setSQLLogger($stack);
...... src sql using .......
dd($stack)

@morozov
Copy link
Member Author

morozov commented Feb 2, 2022

@Igor100 here's an example:

dbal/tests/TestUtil.php

Lines 66 to 71 in 69a38c2

$logger = new Logger('PHPUnit');
$logger->pushHandler(new StreamHandler('/tmp/dbal.log', Logger::DEBUG));
$logger->pushProcessor(new PsrLogMessageProcessor(null, true));
$configuration = (new Configuration())->setMiddlewares([new Logging\Middleware($logger)]);
$conn = DriverManager::getConnection(self::getConnectionParams(), $configuration);

@Tobion
Copy link
Contributor

Tobion commented Apr 7, 2022

Hello. What's the recommended way of disabling sql logging for certain parts of the app?
Removing the sql logger from the connection configuration as done in doctrine/DoctrineBundle#787
does not seem to work anymore. The middleware will always log.
See also symfony/symfony#45974

@morozov
Copy link
Member Author

morozov commented Apr 8, 2022

If you're using Monolog, you can try doing popHandler() / pushHandler() in those parts that need logging to be disabled. Otherwise, it depends on the logger.

@mkopinsky
Copy link

If SQLLogger is deprecated in 3.2, does that mean that it's safe to continue using in ^3.0?

@derrabus
Copy link
Member

If SQLLogger is deprecated in 3.2, does that mean that it's safe to continue using in ^3.0?

Yes. It means your code will break when upgrading to 4.0.

@raziel057
Copy link

From user perspective, deprecating the SQLLogger seems a bit weird to me as we are not able anymore to change it after the connection is created according to different contexts. Maybe you could provide a way to change or remove the logger in the connection decorator created by the middleware?

@morozov
Copy link
Member Author

morozov commented Apr 26, 2022

The middleware is just an adapter between the DBAL driver and a PSR-3 logger. If the logger needs to implement any application-specific logic, it should be implemented in the logger. See #4967 (comment) for example.

@nayodahl
Copy link

Hello @morozov ,
How do you use the equivalent of the deprecated DebugStack(), if there is any ?
I'm ok with adding the Logging\Middleware to the connection's configuration like this :

$logger = new Logger('PHPUnit');
$logger->pushHandler(new StreamHandler('/tmp/dbal.log', Logger::DEBUG));
$logger->pushProcessor(new PsrLogMessageProcessor(null, true));

$configuration = (new Configuration())->setMiddlewares([new Logging\Middleware($logger)]);
$conn          = DriverManager::getConnection(self::getConnectionParams(), $configuration);

But then, how do you get the debugStack like the profiler does for exemple ?
I used to simply inject it in an eventListener and do stuff of the queries...

@morozov
Copy link
Member Author

morozov commented Jun 17, 2022

@nayodahl there's no equivalent of DebugStack. You can implement your own middleware that will wrap calls to the methods you're interested in in the code that captures the time their execution takes. Then you'll need to register both these middlewares. Probably the profiling one first (since you don't want to profile logging) and then the logging one.

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Jul 10, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Rework logger as a driver middleware
8 participants