Log the number of queries built and executed

Signed-off-by: Joas Schilling <coding@schilljs.com>

lib/private/AppFramework/DependencyInjection/DIContainer.php

@@ -61,6 +61,7 @@ use OCP\Files\Folder;
 use OCP\Files\IAppData;
 use OCP\Group\ISubAdmin;
 use OCP\IConfig;
+use OCP\IDBConnection;
 use OCP\IInitialStateService;
 use OCP\IL10N;
 use OCP\ILogger;
@@ -180,7 +181,10 @@ class DIContainer extends SimpleContainer implements IAppContainer {
 				$c->get('Protocol'),
 				$c->get(MiddlewareDispatcher::class),
 				$c->get(IControllerMethodReflector::class),
-				$c->get(IRequest::class)
+				$c->get(IRequest::class),
+				$c->get(IConfig::class),
+				$c->get(IDBConnection::class),
+				$c->get(LoggerInterface::class)
 			);
 		});
 

lib/private/AppFramework/Http/Dispatcher.php

@@ -36,10 +36,15 @@ use OC\AppFramework\Http;
 use OC\AppFramework\Middleware\MiddlewareDispatcher;
 use OC\AppFramework\Utility\ControllerMethodReflector;
 
+use OC\DB\Connection;
 use OCP\AppFramework\Controller;
 use OCP\AppFramework\Http\DataResponse;
 use OCP\AppFramework\Http\Response;
+use OCP\Diagnostics\IQueryLogger;
+use OCP\IConfig;
+use OCP\IDBConnection;
 use OCP\IRequest;
+use Psr\Log\LoggerInterface;
 
 /**
  * Class to dispatch the request to the middleware dispatcher
@@ -58,6 +63,15 @@ class Dispatcher {
 	/** @var IRequest */
 	private $request;
 
+	/** @var IConfig */
+	private $config;
+
+	/** @var IDBConnection|Connection */
+	private $connection;
+
+	/** @var LoggerInterface */
+	private $logger;
+
 	/**
 	 * @param Http $protocol the http protocol with contains all status headers
 	 * @param MiddlewareDispatcher $middlewareDispatcher the dispatcher which
@@ -65,15 +79,24 @@ class Dispatcher {
 	 * @param ControllerMethodReflector $reflector the reflector that is used to inject
 	 * the arguments for the controller
 	 * @param IRequest $request the incoming request
+	 * @param IConfig $config
+	 * @param IDBConnection $connection
+	 * @param LoggerInterface $logger
 	 */
 	public function __construct(Http $protocol,
 								MiddlewareDispatcher $middlewareDispatcher,
 								ControllerMethodReflector $reflector,
-								IRequest $request) {
+								IRequest $request,
+								IConfig $config,
+								IDBConnection $connection,
+								LoggerInterface $logger) {
 		$this->protocol = $protocol;
 		$this->middlewareDispatcher = $middlewareDispatcher;
 		$this->reflector = $reflector;
 		$this->request = $request;
+		$this->config = $config;
+		$this->connection = $connection;
+		$this->logger = $logger;
 	}
 
 
@@ -97,8 +120,36 @@ class Dispatcher {
 
 			$this->middlewareDispatcher->beforeController($controller,
 				$methodName);
+
+			$databaseStatsBefore = [];
+			if ($this->config->getSystemValueBool('debug', false)) {
+				$databaseStatsBefore = $this->connection->getStats();
+			}
+
 			$response = $this->executeController($controller, $methodName);
 
+			if (!empty($databaseStatsBefore)) {
+				$databaseStatsAfter = $this->connection->getStats();
+				$numBuilt = $databaseStatsAfter['built'] - $databaseStatsBefore['built'];
+				$numExecuted = $databaseStatsAfter['executed'] - $databaseStatsBefore['executed'];
+
+				if ($numBuilt > 50) {
+					$this->logger->debug('Controller {class}::{method} created {count} QueryBuilder objects, please check if they are created inside a loop by accident.' , [
+						'class' => (string) get_class($controller),
+						'method' => $methodName,
+						'count' => $numBuilt,
+					]);
+				}
+
+				if ($numExecuted > 100) {
+					$this->logger->warning('Controller {class}::{method} executed {count} queries.' , [
+						'class' => (string) get_class($controller),
+						'method' => $methodName,
+						'count' => $numExecuted,
+					]);
+				}
+			}
+
 			// if an exception appears, the middleware checks if it can handle the
 			// exception and creates a response. If no response is created, it is
 			// assumed that theres no middleware who can handle it and the error is

lib/private/DB/Connection.php

@@ -59,6 +59,12 @@ class Connection extends ReconnectWrapper implements IDBConnection {
 
 	protected $lockedTable = null;
 
+	/** @var int */
+	protected $queriesBuilt = 0;
+
+	/** @var int */
+	protected $queriesExecuted = 0;
+
 	public function connect() {
 		try {
 			return parent::connect();
@@ -68,12 +74,20 @@ class Connection extends ReconnectWrapper implements IDBConnection {
 		}
 	}
 
+	public function getStats(): array {
+		return [
+			'built' => $this->queriesBuilt,
+			'executed' => $this->queriesExecuted,
+		];
+	}
+
 	/**
 	 * Returns a QueryBuilder for the connection.
 	 *
 	 * @return \OCP\DB\QueryBuilder\IQueryBuilder
 	 */
 	public function getQueryBuilder() {
+		$this->queriesBuilt++;
 		return new QueryBuilder(
 			$this,
 			\OC::$server->getSystemConfig(),
@@ -90,6 +104,7 @@ class Connection extends ReconnectWrapper implements IDBConnection {
 	public function createQueryBuilder() {
 		$backtrace = $this->getCallerBacktrace();
 		\OC::$server->getLogger()->debug('Doctrine QueryBuilder retrieved in {backtrace}', ['app' => 'core', 'backtrace' => $backtrace]);
+		$this->queriesBuilt++;
 		return parent::createQueryBuilder();
 	}
 
@@ -102,6 +117,7 @@ class Connection extends ReconnectWrapper implements IDBConnection {
 	public function getExpressionBuilder() {
 		$backtrace = $this->getCallerBacktrace();
 		\OC::$server->getLogger()->debug('Doctrine ExpressionBuilder retrieved in {backtrace}', ['app' => 'core', 'backtrace' => $backtrace]);
+		$this->queriesBuilt++;
 		return parent::getExpressionBuilder();
 	}
 
@@ -191,6 +207,7 @@ class Connection extends ReconnectWrapper implements IDBConnection {
 	public function executeQuery($query, array $params = [], $types = [], QueryCacheProfile $qcp = null) {
 		$query = $this->replaceTablePrefix($query);
 		$query = $this->adapter->fixupStatement($query);
+		$this->queriesExecuted++;
 		return parent::executeQuery($query, $params, $types, $qcp);
 	}
 
@@ -211,6 +228,7 @@ class Connection extends ReconnectWrapper implements IDBConnection {
 	public function executeUpdate($query, array $params = [], array $types = []) {
 		$query = $this->replaceTablePrefix($query);
 		$query = $this->adapter->fixupStatement($query);
+		$this->queriesExecuted++;
 		return parent::executeUpdate($query, $params, $types);
 	}