From de5a7c3c73e5f2f5dda5ec07333c8d3dd89f4540 Mon Sep 17 00:00:00 2001 From: Joas Schilling Date: Wed, 3 Jul 2024 10:39:06 +0200 Subject: [PATCH] fix(db)!: Reimplement the query logger with a doctrine middleware Signed-off-by: Joas Schilling --- lib/composer/composer/autoload_classmap.php | 5 +- lib/composer/composer/autoload_static.php | 5 +- lib/private/DB/BacktraceDebugStack.php | 20 ------ lib/private/DB/Connection.php | 8 +-- lib/private/DB/ConnectionFactory.php | 9 +++ lib/private/DB/DbDataCollector.php | 73 ++++++-------------- lib/private/DB/Logging/Connection.php | 49 +++++++++++++ lib/private/DB/Logging/Driver.php | 34 +++++++++ lib/private/DB/Logging/Middleware.php | 28 ++++++++ lib/private/DB/Logging/Statement.php | 50 ++++++++++++++ lib/private/DB/TDoctrineParameterTypeMap.php | 14 ++++ lib/private/Diagnostics/Query.php | 60 ++++++---------- lib/private/Diagnostics/QueryLogger.php | 46 ++++-------- lib/public/Diagnostics/IQuery.php | 29 ++++---- lib/public/Diagnostics/IQueryLogger.php | 18 ++--- 15 files changed, 278 insertions(+), 170 deletions(-) delete mode 100644 lib/private/DB/BacktraceDebugStack.php create mode 100644 lib/private/DB/Logging/Connection.php create mode 100644 lib/private/DB/Logging/Driver.php create mode 100644 lib/private/DB/Logging/Middleware.php create mode 100644 lib/private/DB/Logging/Statement.php diff --git a/lib/composer/composer/autoload_classmap.php b/lib/composer/composer/autoload_classmap.php index 6feb5778063..93357dbc8e3 100644 --- a/lib/composer/composer/autoload_classmap.php +++ b/lib/composer/composer/autoload_classmap.php @@ -1321,12 +1321,15 @@ return array( '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', diff --git a/lib/composer/composer/autoload_static.php b/lib/composer/composer/autoload_static.php index f717c664d2e..7461a567cfb 100644 --- a/lib/composer/composer/autoload_static.php +++ b/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', diff --git a/lib/private/DB/BacktraceDebugStack.php b/lib/private/DB/BacktraceDebugStack.php deleted file mode 100644 index 4afd3ce6a13..00000000000 --- a/lib/private/DB/BacktraceDebugStack.php +++ /dev/null @@ -1,20 +0,0 @@ -queries[$this->currentQuery]['backtrace'] = $backtrace; - $this->queries[$this->currentQuery]['start'] = $this->start; - } -} diff --git a/lib/private/DB/Connection.php b/lib/private/DB/Connection.php index e0f4a1ddc56..d1fb255eb1b 100644 --- a/lib/private/DB/Connection.php +++ b/lib/private/DB/Connection.php @@ -25,6 +25,7 @@ use OC\DB\QueryBuilder\QueryBuilder; 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 @@ class Connection extends PrimaryReadReplicaConnection { $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); diff --git a/lib/private/DB/ConnectionFactory.php b/lib/private/DB/ConnectionFactory.php index 7bada317f3d..88dbfc59c52 100644 --- a/lib/private/DB/ConnectionFactory.php +++ b/lib/private/DB/ConnectionFactory.php @@ -9,10 +9,14 @@ namespace OC\DB; 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 @@ class ConnectionFactory { $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) { diff --git a/lib/private/DB/DbDataCollector.php b/lib/private/DB/DbDataCollector.php index fcaa74daeab..e30877fa869 100644 --- a/lib/private/DB/DbDataCollector.php +++ b/lib/private/DB/DbDataCollector.php @@ -8,31 +8,22 @@ declare(strict_types = 1); 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 @@ class DbDataCollector extends \OCP\DataCollector\AbstractDataCollector { 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 @@ class DbDataCollector extends \OCP\DataCollector\AbstractDataCollector { * 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; diff --git a/lib/private/DB/Logging/Connection.php b/lib/private/DB/Logging/Connection.php new file mode 100644 index 00000000000..30f1e7444c5 --- /dev/null +++ b/lib/private/DB/Logging/Connection.php @@ -0,0 +1,49 @@ +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; + } +} diff --git a/lib/private/DB/Logging/Driver.php b/lib/private/DB/Logging/Driver.php new file mode 100644 index 00000000000..f787ef66320 --- /dev/null +++ b/lib/private/DB/Logging/Driver.php @@ -0,0 +1,34 @@ +queryLogger, + ); + } +} diff --git a/lib/private/DB/Logging/Middleware.php b/lib/private/DB/Logging/Middleware.php new file mode 100644 index 00000000000..dbfbd49fa6a --- /dev/null +++ b/lib/private/DB/Logging/Middleware.php @@ -0,0 +1,28 @@ +queryLogger, + ); + } +} diff --git a/lib/private/DB/Logging/Statement.php b/lib/private/DB/Logging/Statement.php new file mode 100644 index 00000000000..affb0cf61ba --- /dev/null +++ b/lib/private/DB/Logging/Statement.php @@ -0,0 +1,50 @@ +|array */ + private array $params = []; + + /** @var array|array */ + 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; + } +} diff --git a/lib/private/DB/TDoctrineParameterTypeMap.php b/lib/private/DB/TDoctrineParameterTypeMap.php index f4e06fd9a0c..3e9c53219a0 100644 --- a/lib/private/DB/TDoctrineParameterTypeMap.php +++ b/lib/private/DB/TDoctrineParameterTypeMap.php @@ -28,4 +28,18 @@ trait TDoctrineParameterTypeMap { }; } + protected function convertParameterTypeToJsonSerializable(ArrayParameterType|ParameterType|string $type): string { + return match($type) { + ParameterType::NULL => 'null', + ParameterType::BOOLEAN => 'boolean', + ParameterType::INTEGER => 'integer', + ArrayParameterType::INTEGER => 'integer[]', + ParameterType::STRING => 'string', + ArrayParameterType::STRING => 'string[]', + ParameterType::LARGE_OBJECT => 'lob', + IQueryBuilder::PARAM_DATE, + IQueryBuilder::PARAM_JSON => $type, + default => 'unsupported-type', + }; + } } diff --git a/lib/private/Diagnostics/Query.php b/lib/private/Diagnostics/Query.php index 81610074709..6624d13acab 100644 --- a/lib/private/Diagnostics/Query.php +++ b/lib/private/Diagnostics/Query.php @@ -1,5 +1,6 @@ sql = $sql; - $this->params = $params; - $this->start = $start; - $this->stack = $stack; + public function __construct( + private readonly string $sql, + private readonly ?array $params, + private readonly ?array $types, + private readonly float $start, + private readonly array $stack, + ) { } - public function end($time) { + public function end(float $time): void { $this->end = $time; } - /** - * @return array - */ - public function getParams() { + public function getParams(): ?array { return $this->params; } - /** - * @return string - */ - public function getSql() { + public function getTypes(): ?array { + return $this->types; + } + + public function getSql(): string { return $this->sql; } - /** - * @return float - */ - public function getStart() { + public function getStart(): float { return $this->start; } - - /** - * @return float - */ - public function getDuration() { + + public function getDuration(): float { return $this->end - $this->start; } - public function getStartTime() { + public function getStartTime(): float { return $this->start; } - public function getStacktrace() { + public function getStacktrace(): array { return $this->stack; } } diff --git a/lib/private/Diagnostics/QueryLogger.php b/lib/private/Diagnostics/QueryLogger.php index 5efe99d1a74..8c80207a1a8 100644 --- a/lib/private/Diagnostics/QueryLogger.php +++ b/lib/private/Diagnostics/QueryLogger.php @@ -1,5 +1,6 @@ */ protected CappedMemoryCache $queries; - /** - * QueryLogger constructor. - */ public function __construct() { $this->queries = new CappedMemoryCache(1024); } - /** - * @var bool - Module needs to be activated by some app - */ - private $activated = false; - - /** - * @inheritdoc - */ - public function startQuery($sql, ?array $params = null, ?array $types = null) { + public function startQuery(string $sql, ?array $params = null, ?array $types = null): void { if ($this->activated) { - $this->activeQuery = new Query($sql, $params, microtime(true), $this->getStack()); + $this->activeQuery = new Query($sql, $params, $types, microtime(true), $this->getStack()); } } - private function getStack() { - $stack = debug_backtrace(); - array_shift($stack); - array_shift($stack); - array_shift($stack); - return $stack; + private function getStack(): array { + return debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS); } - /** - * @inheritdoc - */ - public function stopQuery() { + public function stopQuery(): void { if ($this->activated && $this->activeQuery) { $this->activeQuery->end(microtime(true)); $this->queries[(string)$this->index] = $this->activeQuery; @@ -58,17 +48,11 @@ class QueryLogger implements IQueryLogger { } } - /** - * @inheritdoc - */ - public function getQueries() { + public function getQueries(): array { return $this->queries->getData(); } - /** - * @inheritdoc - */ - public function activate() { + public function activate(): void { $this->activated = true; } } diff --git a/lib/public/Diagnostics/IQuery.php b/lib/public/Diagnostics/IQuery.php index 3fe39be27bd..0c717f547d0 100644 --- a/lib/public/Diagnostics/IQuery.php +++ b/lib/public/Diagnostics/IQuery.php @@ -1,5 +1,6 @@