fix(db)!: Reimplement the query logger with a doctrine middleware

Signed-off-by: Joas Schilling <[email protected]>

lib/composer/composer/autoload_classmap.php

@@ -1321,12 +1321,15 @@
     'OC\\DB\\AdapterOCI8' => $baseDir . '/lib/private/DB/AdapterOCI8.php',
     'OC\\DB\\AdapterPgSql' => $baseDir . '/lib/private/DB/AdapterPgSql.php',
     'OC\\DB\\AdapterSqlite' => $baseDir . '/lib/private/DB/AdapterSqlite.php',
-    'OC\\DB\\BacktraceDebugStack' => $baseDir . '/lib/private/DB/BacktraceDebugStack.php',
     'OC\\DB\\Connection' => $baseDir . '/lib/private/DB/Connection.php',
     'OC\\DB\\ConnectionAdapter' => $baseDir . '/lib/private/DB/ConnectionAdapter.php',
     'OC\\DB\\ConnectionFactory' => $baseDir . '/lib/private/DB/ConnectionFactory.php',
     'OC\\DB\\DbDataCollector' => $baseDir . '/lib/private/DB/DbDataCollector.php',
     'OC\\DB\\Exceptions\\DbalException' => $baseDir . '/lib/private/DB/Exceptions/DbalException.php',
+    'OC\\DB\\Logging\\Connection' => $baseDir . '/lib/private/DB/Logging/Connection.php',
+    'OC\\DB\\Logging\\Driver' => $baseDir . '/lib/private/DB/Logging/Driver.php',
+    'OC\\DB\\Logging\\Middleware' => $baseDir . '/lib/private/DB/Logging/Middleware.php',
+    'OC\\DB\\Logging\\Statement' => $baseDir . '/lib/private/DB/Logging/Statement.php',
     'OC\\DB\\Middlewares\\SQLiteCaseSensitiveLike' => $baseDir . '/lib/private/DB/Middlewares/SQLiteCaseSensitiveLike.php',
     'OC\\DB\\Middlewares\\SQLiteJournalMode' => $baseDir . '/lib/private/DB/Middlewares/SQLiteJournalMode.php',
     'OC\\DB\\Middlewares\\SetTransactionIsolationLevel' => $baseDir . '/lib/private/DB/Middlewares/SetTransactionIsolationLevel.php',

lib/composer/composer/autoload_static.php

@@ -1354,12 +1354,15 @@ class ComposerStaticInit749170dad3f5e7f9ca158f5a9f04f6a2
         'OC\\DB\\AdapterOCI8' => __DIR__ . '/../../..' . '/lib/private/DB/AdapterOCI8.php',
         'OC\\DB\\AdapterPgSql' => __DIR__ . '/../../..' . '/lib/private/DB/AdapterPgSql.php',
         'OC\\DB\\AdapterSqlite' => __DIR__ . '/../../..' . '/lib/private/DB/AdapterSqlite.php',
-        'OC\\DB\\BacktraceDebugStack' => __DIR__ . '/../../..' . '/lib/private/DB/BacktraceDebugStack.php',
         'OC\\DB\\Connection' => __DIR__ . '/../../..' . '/lib/private/DB/Connection.php',
         'OC\\DB\\ConnectionAdapter' => __DIR__ . '/../../..' . '/lib/private/DB/ConnectionAdapter.php',
         'OC\\DB\\ConnectionFactory' => __DIR__ . '/../../..' . '/lib/private/DB/ConnectionFactory.php',
         'OC\\DB\\DbDataCollector' => __DIR__ . '/../../..' . '/lib/private/DB/DbDataCollector.php',
         'OC\\DB\\Exceptions\\DbalException' => __DIR__ . '/../../..' . '/lib/private/DB/Exceptions/DbalException.php',
+        'OC\\DB\\Logging\\Connection' => __DIR__ . '/../../..' . '/lib/private/DB/Logging/Connection.php',
+        'OC\\DB\\Logging\\Driver' => __DIR__ . '/../../..' . '/lib/private/DB/Logging/Driver.php',
+        'OC\\DB\\Logging\\Middleware' => __DIR__ . '/../../..' . '/lib/private/DB/Logging/Middleware.php',
+        'OC\\DB\\Logging\\Statement' => __DIR__ . '/../../..' . '/lib/private/DB/Logging/Statement.php',
         'OC\\DB\\Middlewares\\SQLiteCaseSensitiveLike' => __DIR__ . '/../../..' . '/lib/private/DB/Middlewares/SQLiteCaseSensitiveLike.php',
         'OC\\DB\\Middlewares\\SQLiteJournalMode' => __DIR__ . '/../../..' . '/lib/private/DB/Middlewares/SQLiteJournalMode.php',
         'OC\\DB\\Middlewares\\SetTransactionIsolationLevel' => __DIR__ . '/../../..' . '/lib/private/DB/Middlewares/SetTransactionIsolationLevel.php',

lib/private/DB/Connection.php

@@ -25,6 +25,7 @@
 use OC\SystemConfig;
 use OCP\DB\QueryBuilder\IQueryBuilder;
 use OCP\Diagnostics\IEventLogger;
+use OCP\Diagnostics\IQueryLogger;
 use OCP\IRequestId;
 use OCP\PreConditionNotMetException;
 use OCP\Profiler\IProfiler;
@@ -99,14 +100,11 @@ public function __construct(
 		$this->logRequestId = $this->systemConfig->getValue('db.log_request_id', false);
 		$this->requestId = Server::get(IRequestId::class)->getId();
 
-		/** @var \OCP\Profiler\IProfiler */
+		/** @var IProfiler */
 		$profiler = Server::get(IProfiler::class);
 		if ($profiler->isEnabled()) {
-			$this->dbDataCollector = new DbDataCollector($this);
+			$this->dbDataCollector = new DbDataCollector(Server::get(IQueryLogger::class));
 			$profiler->add($this->dbDataCollector);
-			$debugStack = new BacktraceDebugStack();
-			$this->dbDataCollector->setDebugStack($debugStack);
-			// FIXME $this->_config->setSQLLogger($debugStack);
 		}
 
 		$this->setNestTransactionsWithSavepoints(true);

lib/private/DB/ConnectionFactory.php

@@ -9,10 +9,14 @@
 
 use Doctrine\DBAL\Configuration;
 use Doctrine\DBAL\DriverManager;
+use OC\DB\Logging\Middleware;
 use OC\DB\Middlewares\SetTransactionIsolationLevel;
 use OC\DB\Middlewares\SQLiteCaseSensitiveLike;
 use OC\DB\Middlewares\SQLiteJournalMode;
 use OC\SystemConfig;
+use OCP\Diagnostics\IQueryLogger;
+use OCP\Profiler\IProfiler;
+use OCP\Server;
 
 /**
  * Takes care of creating and configuring Doctrine connections.
@@ -108,6 +112,11 @@ public function getConnection($type, $additionalConnectionParams) {
 
 		$doctrineConfiguration = new Configuration();
 		$doctrineMiddlewares = $doctrineConfiguration->getMiddlewares();
+		/** @var IProfiler */
+		$profiler = Server::get(IProfiler::class);
+		if ($profiler->isEnabled()) {
+			$doctrineMiddlewares[] = new Middleware(Server::get(IQueryLogger::class));
+		}
 		$doctrineMiddlewares[] = new SetTransactionIsolationLevel();
 
 		switch ($normalizedType) {

lib/private/DB/DbDataCollector.php

@@ -8,31 +8,22 @@
 
 namespace OC\DB;
 
-use Doctrine\DBAL\Types\ConversionException;
-use Doctrine\DBAL\Types\Type;
 use OC\AppFramework\Http\Request;
+use OC\Diagnostics\Query;
 use OCP\AppFramework\Http\Response;
+use OCP\Diagnostics\IQueryLogger;
 
 class DbDataCollector extends \OCP\DataCollector\AbstractDataCollector {
-	protected ?BacktraceDebugStack $debugStack = null;
-	private Connection $connection;
-
-	/**
-	 * DbDataCollector constructor.
-	 */
-	public function __construct(Connection $connection) {
-		$this->connection = $connection;
-	}
-
-	public function setDebugStack(BacktraceDebugStack $debugStack, $name = 'default'): void {
-		$this->debugStack = $debugStack;
+	public function __construct(
+		private readonly IQueryLogger $queryLogger,
+	) {
 	}
 
 	/**
 	 * @inheritDoc
 	 */
 	public function collect(Request $request, Response $response, ?\Throwable $exception = null): void {
-		$queries = $this->sanitizeQueries($this->debugStack->queries);
+		$queries = $this->sanitizeQueries($this->queryLogger->getQueries());
 
 		$this->data = [
 			'queries' => $queries,
@@ -55,37 +46,19 @@ private function sanitizeQueries(array $queries): array {
 		return $queries;
 	}
 
-	private function sanitizeQuery(array $query): array {
-		$query['explainable'] = true;
-		$query['runnable'] = true;
-		if ($query['params'] === null) {
-			$query['params'] = [];
-		}
-		if (!\is_array($query['params'])) {
-			$query['params'] = [$query['params']];
-		}
-		if (!\is_array($query['types'])) {
-			$query['types'] = [];
-		}
-		foreach ($query['params'] as $j => $param) {
-			$e = null;
-			if (isset($query['types'][$j])) {
-				// Transform the param according to the type
-				$type = $query['types'][$j];
-				if (\is_string($type)) {
-					$type = Type::getType($type);
-				}
-				if ($type instanceof Type) {
-					$query['types'][$j] = $type->getBindingType();
-					try {
-						$param = $type->convertToDatabaseValue($param, $this->connection->getDatabasePlatform());
-					} catch (\TypeError $e) {
-					} catch (ConversionException $e) {
-					}
-				}
-			}
+	private function sanitizeQuery(Query $queryObject): array {
+		$query = [
+			'sql' => $queryObject->getSql(),
+			'params' => $queryObject->getParams() ?? [],
+			'types' => $queryObject->getTypes() ?? [],
+			'executionMS' => $queryObject->getDuration(),
+			'backtrace' => $queryObject->getStacktrace(),
+			'explainable' => true,
+			'runnable' => true,
+		];
 
-			[$query['params'][$j], $explainable, $runnable] = $this->sanitizeParam($param, $e);
+		foreach ($query['params'] as $j => $param) {
+			[$query['params'][$j], $explainable, $runnable] = $this->sanitizeParam($param);
 			if (!$explainable) {
 				$query['explainable'] = false;
 			}
@@ -105,20 +78,16 @@ private function sanitizeQuery(array $query): array {
 	 * indicating if the original value was kept (allowing to use the sanitized
 	 * value to explain the query).
 	 */
-	private function sanitizeParam($var, ?\Throwable $error): array {
+	private function sanitizeParam($var): array {
 		if (\is_object($var)) {
-			return [$o = new ObjectParameter($var, $error), false, $o->isStringable() && !$error];
-		}
-
-		if ($error) {
-			return ['⚠ '.$error->getMessage(), false, false];
+			return [$o = new ObjectParameter($var, null), false, $o->isStringable()];
 		}
 
 		if (\is_array($var)) {
 			$a = [];
 			$explainable = $runnable = true;
 			foreach ($var as $k => $v) {
-				[$value, $e, $r] = $this->sanitizeParam($v, null);
+				[$value, $e, $r] = $this->sanitizeParam($v);
 				$explainable = $explainable && $e;
 				$runnable = $runnable && $r;
 				$a[$k] = $value;

lib/private/DB/Logging/Connection.php

@@ -0,0 +1,49 @@
+<?php
+
+declare(strict_types=1);
+/**
+ * SPDX-FileCopyrightText: 2024 Nextcloud GmbH and Nextcloud contributors
+ * SPDX-FileCopyrightText: 2024 Doctrine Project
+ * SPDX-License-Identifier: MIT
+ */
+
+namespace OC\DB\Logging;
+
+use Doctrine\DBAL\Driver\Connection as ConnectionInterface;
+use Doctrine\DBAL\Driver\Middleware\AbstractConnectionMiddleware;
+use Doctrine\DBAL\Driver\Result;
+use Doctrine\DBAL\Driver\Statement as DriverStatement;
+use OCP\Diagnostics\IQueryLogger;
+
+final class Connection extends AbstractConnectionMiddleware {
+	public function __construct(
+		ConnectionInterface $connection,
+		private readonly IQueryLogger $queryLogger,
+	) {
+		parent::__construct($connection);
+	}
+
+	public function prepare(string $sql): DriverStatement {
+		return new Statement(
+			parent::prepare($sql),
+			$this->queryLogger,
+			$sql,
+		);
+	}
+
+	public function query(string $sql): Result {
+		$this->queryLogger->startQuery($sql);
+		$result = parent::query($sql);
+		$this->queryLogger->stopQuery();
+
+		return $result;
+	}
+
+	public function exec(string $sql): int|string {
+		$this->queryLogger->startQuery($sql);
+		$result = parent::exec($sql);
+		$this->queryLogger->stopQuery();
+
+		return $result;
+	}
+}

lib/private/DB/Logging/Driver.php

@@ -0,0 +1,34 @@
+<?php
+
+declare(strict_types=1);
+/**
+ * SPDX-FileCopyrightText: 2024 Nextcloud GmbH and Nextcloud contributors
+ * SPDX-FileCopyrightText: 2024 Doctrine Project
+ * SPDX-License-Identifier: MIT
+ */
+
+namespace OC\DB\Logging;
+
+use Doctrine\DBAL\Driver as DriverInterface;
+use Doctrine\DBAL\Driver\Middleware\AbstractDriverMiddleware;
+use OCP\Diagnostics\IQueryLogger;
+use SensitiveParameter;
+
+final class Driver extends AbstractDriverMiddleware {
+	public function __construct(
+		DriverInterface $driver,
+		private readonly IQueryLogger $queryLogger,
+	) {
+		parent::__construct($driver);
+	}
+
+	public function connect(
+		#[SensitiveParameter]
+		array $params,
+	): Connection {
+		return new Connection(
+			parent::connect($params),
+			$this->queryLogger,
+		);
+	}
+}

lib/private/DB/Logging/Middleware.php

@@ -0,0 +1,28 @@
+<?php
+
+declare(strict_types=1);
+/**
+ * SPDX-FileCopyrightText: 2024 Nextcloud GmbH and Nextcloud contributors
+ * SPDX-FileCopyrightText: 2024 Doctrine Project
+ * SPDX-License-Identifier: MIT
+ */
+
+namespace OC\DB\Logging;
+
+use Doctrine\DBAL\Driver as DriverInterface;
+use Doctrine\DBAL\Driver\Middleware as MiddlewareInterface;
+use OCP\Diagnostics\IQueryLogger;
+
+final class Middleware implements MiddlewareInterface {
+	public function __construct(
+		private readonly IQueryLogger $queryLogger,
+	) {
+	}
+
+	public function wrap(DriverInterface $driver): DriverInterface {
+		return new Driver(
+			$driver,
+			$this->queryLogger,
+		);
+	}
+}

lib/private/DB/Logging/Statement.php

@@ -0,0 +1,50 @@
+<?php
+
+declare(strict_types=1);
+/**
+ * SPDX-FileCopyrightText: 2024 Nextcloud GmbH and Nextcloud contributors
+ * SPDX-FileCopyrightText: 2024 Doctrine Project
+ * SPDX-License-Identifier: MIT
+ */
+
+namespace OC\DB\Logging;
+
+use Doctrine\DBAL\Driver\Middleware\AbstractStatementMiddleware;
+use Doctrine\DBAL\Driver\Result as ResultInterface;
+use Doctrine\DBAL\Driver\Statement as StatementInterface;
+use Doctrine\DBAL\ParameterType;
+use OC\DB\TDoctrineParameterTypeMap;
+use OCP\Diagnostics\IQueryLogger;
+
+final class Statement extends AbstractStatementMiddleware {
+	use TDoctrineParameterTypeMap;
+
+	/** @var array<int,mixed>|array<string,mixed> */
+	private array $params = [];
+
+	/** @var array<int,string>|array<string,string> */
+	private array $types = [];
+
+	public function __construct(
+		StatementInterface $statement,
+		private readonly IQueryLogger $queryLogger,
+		private readonly string $sql,
+	) {
+		parent::__construct($statement);
+	}
+
+	public function bindValue(int|string $param, mixed $value, ParameterType $type): void {
+		$this->params[$param] = $value;
+		$this->types[$param] = $this->convertParameterTypeToJsonSerializable($type);
+
+		parent::bindValue($param, $value, $type);
+	}
+
+	public function execute(): ResultInterface {
+		$this->queryLogger->startQuery($this->sql, $this->params, $this->types);
+		$result = parent::execute();
+		$this->queryLogger->stopQuery();
+
+		return $result;
+	}
+}