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

Signed-off-by: Joas Schilling <coding@schilljs.com>
This commit is contained in:
Joas Schilling 2024-07-03 10:39:06 +02:00
parent 1370693133
commit de5a7c3c73
No known key found for this signature in database
GPG key ID: 74434EFE0D2E2205
15 changed files with 278 additions and 170 deletions

View file

@ -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',

View file

@ -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',

View file

@ -1,20 +0,0 @@
<?php
declare(strict_types=1);
/**
* SPDX-FileCopyrightText: 2022 Nextcloud GmbH and Nextcloud contributors
* SPDX-License-Identifier: AGPL-3.0-or-later
*/
namespace OC\DB;
use Doctrine\DBAL\Logging\DebugStack;
class BacktraceDebugStack extends DebugStack {
public function startQuery($sql, ?array $params = null, ?array $types = null) {
parent::startQuery($sql, $params, $types);
$backtrace = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);
$this->queries[$this->currentQuery]['backtrace'] = $backtrace;
$this->queries[$this->currentQuery]['start'] = $this->start;
}
}

View file

@ -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);

View file

@ -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) {

View file

@ -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;

View file

@ -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;
}
}

View file

@ -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,
);
}
}

View file

@ -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,
);
}
}

View file

@ -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;
}
}

View file

@ -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',
};
}
}

View file

@ -1,5 +1,6 @@
<?php
declare(strict_types=1);
/**
* SPDX-FileCopyrightText: 2016-2024 Nextcloud GmbH and Nextcloud contributors
* SPDX-FileCopyrightText: 2016 ownCloud, Inc.
@ -10,65 +11,46 @@ namespace OC\Diagnostics;
use OCP\Diagnostics\IQuery;
class Query implements IQuery {
private $sql;
private float $end = 0;
private $params;
private $start;
private $end;
private $stack;
/**
* @param string $sql
* @param array $params
* @param int $start
*/
public function __construct($sql, $params, $start, array $stack) {
$this->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;
}
}

View file

@ -1,5 +1,6 @@
<?php
declare(strict_types=1);
/**
* SPDX-FileCopyrightText: 2016-2024 Nextcloud GmbH and Nextcloud contributors
* SPDX-FileCopyrightText: 2016 ownCloud, Inc.
@ -11,45 +12,34 @@ use OCP\Cache\CappedMemoryCache;
use OCP\Diagnostics\IQueryLogger;
class QueryLogger implements IQueryLogger {
/**
* Module needs to be activated by some app, e.g. profiler
*/
private bool $activated = false;
protected int $index = 0;
protected ?Query $activeQuery = null;
/** @var CappedMemoryCache<Query> */
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;
}
}

View file

@ -1,5 +1,6 @@
<?php
declare(strict_types=1);
/**
* SPDX-FileCopyrightText: 2016-2024 Nextcloud GmbH and Nextcloud contributors
* SPDX-FileCopyrightText: 2016 ownCloud, Inc.
@ -11,40 +12,44 @@ namespace OCP\Diagnostics;
* Interface IQuery
*
* @since 8.0.0
* @since 30.0.0 The IQueryLogger no longer extends `\Doctrine\DBAL\Logging\SQLLogger`.
* Due to more underlying changes the types and parameter content could not be kept consistent.
*/
interface IQuery {
/**
* @return string
* @since 8.0.0
*/
public function getSql();
public function getSql(): string;
/**
* @return array
* @since 8.0.0
*/
public function getParams();
public function getParams(): ?array;
/**
* @since 30.0.0
*/
public function getTypes(): ?array;
/**
* @return float
* @since 8.0.0
*/
public function getDuration();
public function getDuration(): float;
/**
* @return float
* @since 11.0.0
*/
public function getStartTime();
public function getStartTime(): float;
/**
* @return array
* @since 11.0.0
*/
public function getStacktrace();
public function getStacktrace(): array;
/**
* @return array
* @since 12.0.0
* @since 30.0.0 Documented return type was fixed to actual type float
* @deprecated 30.0.0 Use {@see self::getStartTime()} instead
*/
public function getStart();
public function getStart(): float;
}

View file

@ -1,5 +1,6 @@
<?php
declare(strict_types=1);
/**
* SPDX-FileCopyrightText: 2016-2024 Nextcloud GmbH and Nextcloud contributors
* SPDX-FileCopyrightText: 2016 ownCloud, Inc.
@ -7,14 +8,13 @@
*/
namespace OCP\Diagnostics;
use Doctrine\DBAL\Logging\SQLLogger;
/**
* Interface IQueryLogger
*
* @since 8.0.0
* @since 30.0.0 No longer extends `\Doctrine\DBAL\Logging\SQLLogger` as it was removed upstream
*/
interface IQueryLogger extends SQLLogger {
interface IQueryLogger {
/**
* Mark the start of a query providing query SQL statement, its parameters and types.
* This method should be called as close to the DB as possible and after
@ -24,26 +24,26 @@ interface IQueryLogger extends SQLLogger {
* @param array|null $params
* @param array|null $types
* @since 8.0.0
* @since 30.0.0 All arguments are typed
*/
public function startQuery($sql, ?array $params = null, ?array $types = null);
public function startQuery(string $sql, ?array $params = null, ?array $types = null): void;
/**
* Mark the end of the current active query. Ending query should store \OCP\Diagnostics\IQuery to
* be returned with getQueries() method.
*
* @return mixed
* @since 8.0.0
*/
public function stopQuery();
public function stopQuery(): void;
/**
* This method should return all \OCP\Diagnostics\IQuery objects stored using
* startQuery()/stopQuery() methods.
*
* @return \OCP\Diagnostics\IQuery[]
* @return IQuery[]
* @since 8.0.0
*/
public function getQueries();
public function getQueries(): array;
/**
* Activate the module for the duration of the request. Deactivated module
@ -53,5 +53,5 @@ interface IQueryLogger extends SQLLogger {
*
* @since 12.0.0
*/
public function activate();
public function activate(): void;
}