feat: extend database logger context

CHANGELOG.md

@@ -1,5 +1,10 @@
 # CHANGELOG
 
+v2.9.0 (27.03.2024)
+-------------------
+- Added `logInterpolatedQueries` for detailed query logging and refined `logQueryParameters` to accurately log query parameters as arrays, enhancing ORM debugging and monitoring. @lotyp (#165)
+- Improved logging with enriched context in Driver.php, including driver details and query parameters. @lotyp (#165)
+
 v2.8.1 (08.02.2024)
 -------------------
 - Fix compiling of Fragment with parameters in the returning() definition by @msmakouz (#161)

src/Config/DriverConfig.php

@@ -26,6 +26,7 @@ abstract class DriverConfig
 
     protected array $defaultOptions = [
         'withDatetimeMicroseconds' => false,
+        'logInterpolatedQueries' => false,
         'logQueryParameters' => false,
     ];
 
@@ -42,6 +43,7 @@ abstract class DriverConfig
      * @param bool $readonly Disable write expressions
      * @param array{
      *     withDatetimeMicroseconds?: bool,
+     *     logInterpolatedQueries?: bool,
      *     logQueryParameters?: bool
      * } $options
      */

src/Driver/Driver.php

@@ -476,10 +476,19 @@ protected function statement(string $query, iterable $parameters = [], bool $ret
             throw $e;
         } finally {
             if ($this->logger !== null) {
-                $queryString = $this->config->options['logQueryParameters']
+                $queryString = $this->config->options['logInterpolatedQueries']
                     ? Interpolator::interpolate($query, $parameters, $this->config->options)
                     : $query;
-                $context = $this->defineLoggerContext($queryStart, $statement ?? null);
+
+                $contextParameters = $this->config->options['logQueryParameters']
+                    ? $parameters
+                    : [];
+
+                $context = $this->defineLoggerContext(
+                    $queryStart,
+                    $statement ?? null,
+                    $contextParameters
+                );
 
                 if (isset($e)) {
                     $this->logger->error($queryString, $context);
@@ -676,16 +685,25 @@ protected function getPDO(): PDO|PDOInterface
      * Creating a context for logging
      *
      * @param float $queryStart Query start time
+     * @param PDOStatement|PDOStatementInterface|null $statement Statement object
+     * @param iterable $parameters Query parameters
+     *
+     * @return array
      */
-    protected function defineLoggerContext(float $queryStart, PDOStatement|PDOStatementInterface|null $statement): array
+    protected function defineLoggerContext(float $queryStart, PDOStatement|PDOStatementInterface|null $statement, iterable $parameters = []): array
     {
         $context = [
+            'driver' => $this->getType(),
             'elapsed' => microtime(true) - $queryStart,
         ];
         if ($statement !== null) {
             $context['rowCount'] = $statement->rowCount();
         }
 
+        foreach ($parameters as $parameter) {
+            $context['parameters'][] = Interpolator::resolveValue($parameter, $this->config->options);
+        }
+
         return $context;
     }
 }

src/Query/Interpolator.php

@@ -38,16 +38,7 @@ public static function interpolate(string $query, iterable $parameters = [], arr
             return $query;
         }
 
-        $named = [];
-        $unnamed = [];
-
-        foreach ($parameters as $k => $v) {
-            if (\is_int($k)) {
-                $unnamed[] = $v;
-            } else {
-                $named[\ltrim($k, ':')] = $v;
-            }
-        }
+        ['named' => $named, 'unnamed' => $unnamed] = self::categorizeParameters($parameters);
 
         return \preg_replace_callback(
             '/(?<dq>"(?:\\\\\"|[^"])*")|(?<sq>\'(?:\\\\\'|[^\'])*\')|(?<ph>\\?)|(?<named>:[a-z_\\d]+)/',
@@ -82,7 +73,7 @@ static function ($match) use (&$named, &$unnamed, $options) {
      *
      * @psalm-return non-empty-string
      */
-    private static function resolveValue(mixed $parameter, array $options): string
+    public static function resolveValue(mixed $parameter, array $options): string
     {
         if ($parameter instanceof ParameterInterface) {
             return self::resolveValue($parameter->getValue(), $options);
@@ -141,4 +132,27 @@ private static function escapeStringValue(string $value): string
             '\\' => '\\\\',
         ]);
     }
+
+    /**
+     * Categorizes parameters into named and unnamed.
+     *
+     * @param iterable $parameters Parameters to categorize.
+     *
+     * @return array{named: array<string, mixed>, unnamed: list<mixed>} An associative array with keys 'named' and 'unnamed'.
+     */
+    private static function categorizeParameters(iterable $parameters): array
+    {
+        $named = [];
+        $unnamed = [];
+
+        foreach ($parameters as $k => $v) {
+            if (\is_int($k)) {
+                $unnamed[] = $v;
+            } else {
+                $named[\ltrim($k, ':')] = $v;
+            }
+        }
+
+        return ['named' => $named, 'unnamed' => $unnamed];
+    }
 }

tests/Database/Unit/Driver/AbstractDriverTest.php

@@ -128,7 +128,7 @@ public function testLogsWithEnabledInterpolation(): void
             ->willReturn($this->createMock(PDOStatementInterface::class));
 
         $driver = TestDriver::createWith(
-            new SQLiteDriverConfig(options: ['logQueryParameters' => true]),
+            new SQLiteDriverConfig(options: ['logInterpolatedQueries' => true]),
             $this->createMock(HandlerInterface::class),
             $this->createMock(BuilderInterface::class),
             $pdo
@@ -147,6 +147,53 @@ public function testLogsWithEnabledInterpolation(): void
         );
     }
 
+    public function testLogsQueryParameters(): void
+    {
+        $pdo = $this->createMock(PDOInterface::class);
+        $pdo
+            ->expects($this->once())
+            ->method('prepare')
+            ->willReturn($this->createMock(PDOStatementInterface::class));
+
+        $driver = TestDriver::createWith(
+            new SQLiteDriverConfig(options: [
+                'logInterpolatedQueries' => false,
+                'logQueryParameters' => true,
+            ]),
+            $this->createMock(HandlerInterface::class),
+            $this->createMock(BuilderInterface::class),
+            $pdo
+        );
+
+        $logger = $this->createMock(LoggerInterface::class);
+        $logger
+            ->expects($this->once())
+            ->method('info')
+            ->with(
+                $this->equalTo('SELECT * FROM sample_table WHERE id IN (?, ?, ?) ORDER BY id ASC'),
+                $this->callback(function (array $context) {
+                    if (!isset($context['parameters'])) {
+                        return false;
+                    }
+
+                    $parametersAsString = array_map('strval', $context['parameters']);
+
+                    $expectedParameters = ['1', '2', '3'];
+                    if ($parametersAsString !== $expectedParameters) {
+                        return false;
+                    }
+
+                    return isset($context['driver']);
+                })
+            );
+        $driver->setLogger($logger);
+
+        $driver->query(
+            'SELECT * FROM sample_table WHERE id IN (?, ?, ?) ORDER BY id ASC',
+            [1, 2, 3]
+        );
+    }
+
     public function testLogsWithEnabledInterpolationAndWithDatetimeMicroseconds(): void
     {
         $pdo = $this->createMock(PDOInterface::class);
@@ -156,7 +203,7 @@ public function testLogsWithEnabledInterpolationAndWithDatetimeMicroseconds(): v
             ->willReturn($this->createMock(PDOStatementInterface::class));
 
         $driver = TestDriver::createWith(
-            new SQLiteDriverConfig(options: ['logQueryParameters' => true, 'withDatetimeMicroseconds' => true]),
+            new SQLiteDriverConfig(options: ['logInterpolatedQueries' => true, 'withDatetimeMicroseconds' => true]),
             $this->createMock(HandlerInterface::class),
             $this->createMock(BuilderInterface::class),
             $pdo