Merge pull request #23047 from nextcloud/techdebt/noid/warn-on-database-abuse

Log the number of queries built and executed

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

@@ -35,11 +35,14 @@ namespace OC\AppFramework\Http;
 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\IConfig;
+use OCP\IDBConnection;
 use OCP\IRequest;
+use Psr\Log\LoggerInterface;
 
 /**
  * Class to dispatch the request to the middleware dispatcher
@@ -58,6 +61,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 +77,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 +118,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);
 	}
 

tests/lib/AppFramework/Http/DispatcherTest.php

@@ -33,6 +33,9 @@ use OCP\AppFramework\Http\DataResponse;
 use OCP\AppFramework\Http\JSONResponse;
 use OCP\AppFramework\Http\Response;
 use OCP\IConfig;
+use OCP\IRequest;
+use PHPUnit\Framework\MockObject\MockObject;
+use Psr\Log\LoggerInterface;
 
 class TestController extends Controller {
 	/**
@@ -72,7 +75,12 @@ class TestController extends Controller {
 	}
 }
 
-
+/**
+ * Class DispatcherTest
+ *
+ * @package Test\AppFramework\Http
+ * @group DB
+ */
 class DispatcherTest extends \Test\TestCase {
 	/** @var MiddlewareDispatcher */
 	private $middlewareDispatcher;
@@ -80,16 +88,24 @@ class DispatcherTest extends \Test\TestCase {
 	private $dispatcher;
 	private $controllerMethod;
 	private $response;
+	/** @var IRequest|MockObject  */
 	private $request;
 	private $lastModified;
 	private $etag;
+	/** @var Http|MockObject  */
 	private $http;
 	private $reflector;
+	/** @var IConfig|MockObject  */
+	private $config;
+	/** @var LoggerInterface|MockObject  */
+	private $logger;
 
 	protected function setUp(): void {
 		parent::setUp();
 		$this->controllerMethod = 'test';
 
+		$this->config = $this->createMock(IConfig::class);
+		$this->logger = $this->createMock(LoggerInterface::class);
 		$app = $this->getMockBuilder(
 			'OC\AppFramework\DependencyInjection\DIContainer')
 			->disableOriginalConstructor()
@@ -99,7 +115,7 @@ class DispatcherTest extends \Test\TestCase {
 			->disableOriginalConstructor()
 			->getMock();
 		$this->http = $this->getMockBuilder(
-			'\OC\AppFramework\Http')
+			\OC\AppFramework\Http::class)
 			->disableOriginalConstructor()
 			->getMock();
 
@@ -124,7 +140,10 @@ class DispatcherTest extends \Test\TestCase {
 			$this->http,
 			$this->middlewareDispatcher,
 			$this->reflector,
-			$this->request
+			$this->request,
+			$this->config,
+			\OC::$server->getDatabaseConnection(),
+			$this->logger
 		);
 
 		$this->response = $this->createMock(Response::class);
@@ -299,7 +318,10 @@ class DispatcherTest extends \Test\TestCase {
 		);
 		$this->dispatcher = new Dispatcher(
 			$this->http, $this->middlewareDispatcher, $this->reflector,
-			$this->request
+			$this->request,
+			$this->config,
+			\OC::$server->getDatabaseConnection(),
+			$this->logger
 		);
 		$controller = new TestController('app', $this->request);
 
@@ -330,7 +352,10 @@ class DispatcherTest extends \Test\TestCase {
 		);
 		$this->dispatcher = new Dispatcher(
 			$this->http, $this->middlewareDispatcher, $this->reflector,
-			$this->request
+			$this->request,
+			$this->config,
+			\OC::$server->getDatabaseConnection(),
+			$this->logger
 		);
 		$controller = new TestController('app', $this->request);
 
@@ -364,7 +389,10 @@ class DispatcherTest extends \Test\TestCase {
 		);
 		$this->dispatcher = new Dispatcher(
 			$this->http, $this->middlewareDispatcher, $this->reflector,
-			$this->request
+			$this->request,
+			$this->config,
+			\OC::$server->getDatabaseConnection(),
+			$this->logger
 		);
 		$controller = new TestController('app', $this->request);
 
@@ -397,7 +425,10 @@ class DispatcherTest extends \Test\TestCase {
 		);
 		$this->dispatcher = new Dispatcher(
 			$this->http, $this->middlewareDispatcher, $this->reflector,
-			$this->request
+			$this->request,
+			$this->config,
+			\OC::$server->getDatabaseConnection(),
+			$this->logger
 		);
 		$controller = new TestController('app', $this->request);
 
@@ -431,7 +462,10 @@ class DispatcherTest extends \Test\TestCase {
 		);
 		$this->dispatcher = new Dispatcher(
 			$this->http, $this->middlewareDispatcher, $this->reflector,
-			$this->request
+			$this->request,
+			$this->config,
+			\OC::$server->getDatabaseConnection(),
+			$this->logger
 		);
 		$controller = new TestController('app', $this->request);
 
@@ -467,7 +501,10 @@ class DispatcherTest extends \Test\TestCase {
 		);
 		$this->dispatcher = new Dispatcher(
 			$this->http, $this->middlewareDispatcher, $this->reflector,
-			$this->request
+			$this->request,
+			$this->config,
+			\OC::$server->getDatabaseConnection(),
+			$this->logger
 		);
 		$controller = new TestController('app', $this->request);