From 9fec4031b30f5ab56af2f8c284672fcd444e8b62 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Piotr=20Mr=C3=B3wczy=C5=84ski?= Date: Thu, 20 Apr 2017 11:31:00 +0200 Subject: [PATCH] Adjust query/event logging code in favour of more complex owncloud/diagnostics (#27643) * Adjust query/event logging code in favour of more complex owncloud/diagnostics * Add descriptions to IQueryLogger and IEventLogger interfaces --- lib/private/DB/Connection.php | 3 - lib/private/Diagnostics/EventLogger.php | 39 ++++++++++-- lib/private/Diagnostics/NullEventLogger.php | 58 ------------------ lib/private/Diagnostics/NullQueryLogger.php | 46 -------------- lib/private/Diagnostics/Query.php | 9 ++- lib/private/Diagnostics/QueryLogger.php | 33 +++++++++-- lib/private/Server.php | 15 ++--- lib/private/legacy/db/statementwrapper.php | 9 +-- lib/public/Diagnostics/IEventLogger.php | 29 ++++++++- lib/public/Diagnostics/IQuery.php | 5 ++ lib/public/Diagnostics/IQueryLogger.php | 25 ++++++++ tests/lib/Diagnostics/EventLoggerTest.php | 66 +++++++++++++++++++++ tests/lib/Diagnostics/QueryLoggerTest.php | 54 +++++++++++++++++ 13 files changed, 254 insertions(+), 137 deletions(-) delete mode 100644 lib/private/Diagnostics/NullEventLogger.php delete mode 100644 lib/private/Diagnostics/NullQueryLogger.php create mode 100644 tests/lib/Diagnostics/EventLoggerTest.php create mode 100644 tests/lib/Diagnostics/QueryLoggerTest.php diff --git a/lib/private/DB/Connection.php b/lib/private/DB/Connection.php index 9e11671264..6b56ae8ad5 100644 --- a/lib/private/DB/Connection.php +++ b/lib/private/DB/Connection.php @@ -167,9 +167,6 @@ class Connection extends \Doctrine\DBAL\Connection implements IDBConnection { $statement = $this->replaceTablePrefix($statement); $statement = $this->adapter->fixupStatement($statement); - if(\OC::$server->getSystemConfig()->getValue( 'log_query', false)) { - \OCP\Util::writeLog('core', 'DB prepare : '.$statement, \OCP\Util::DEBUG); - } return parent::prepare($statement); } diff --git a/lib/private/Diagnostics/EventLogger.php b/lib/private/Diagnostics/EventLogger.php index 5abaae3f1d..846be7efc5 100644 --- a/lib/private/Diagnostics/EventLogger.php +++ b/lib/private/Diagnostics/EventLogger.php @@ -4,6 +4,8 @@ * * @author Morris Jobke * @author Robin Appelman + * @author Thomas Müller + * @author Piotr Mrowczynski * * @license AGPL-3.0 * @@ -29,28 +31,53 @@ class EventLogger implements IEventLogger { /** * @var \OC\Diagnostics\Event[] */ - private $events = array(); + private $events = []; + + /** + * @var bool - Module needs to be activated by some app + */ + private $activated = false; + /** + * @inheritdoc + */ public function start($id, $description) { - $this->events[$id] = new Event($id, $description, microtime(true)); + if ($this->activated){ + $this->events[$id] = new Event($id, $description, microtime(true)); + } } + /** + * @inheritdoc + */ public function end($id) { - if (isset($this->events[$id])) { + if ($this->activated && isset($this->events[$id])) { $timing = $this->events[$id]; $timing->end(microtime(true)); } } + /** + * @inheritdoc + */ public function log($id, $description, $start, $end) { - $this->events[$id] = new Event($id, $description, $start); - $this->events[$id]->end($end); + if ($this->activated) { + $this->events[$id] = new Event($id, $description, $start); + $this->events[$id]->end($end); + } } /** - * @return \OCP\Diagnostics\IEvent[] + * @inheritdoc */ public function getEvents() { return $this->events; } + + /** + * @inheritdoc + */ + public function activate() { + $this->activated = true; + } } diff --git a/lib/private/Diagnostics/NullEventLogger.php b/lib/private/Diagnostics/NullEventLogger.php deleted file mode 100644 index 9fe7461eb4..0000000000 --- a/lib/private/Diagnostics/NullEventLogger.php +++ /dev/null @@ -1,58 +0,0 @@ - - * @author Robin Appelman - * - * @license AGPL-3.0 - * - * This code is free software: you can redistribute it and/or modify - * it under the terms of the GNU Affero General Public License, version 3, - * as published by the Free Software Foundation. - * - * This program is distributed in the hope that it will be useful, - * but WITHOUT ANY WARRANTY; without even the implied warranty of - * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the - * GNU Affero General Public License for more details. - * - * You should have received a copy of the GNU Affero General Public License, version 3, - * along with this program. If not, see - * - */ - -namespace OC\Diagnostics; - -use OCP\Diagnostics\IEventLogger; - -/** - * Dummy event logger that doesn't actually log anything - */ -class NullEventLogger implements IEventLogger { - /** - * Mark the start of an event - * - * @param $id - * @param $description - */ - public function start($id, $description) { - } - - /** - * Mark the end of an event - * - * @param $id - */ - public function end($id) { - } - - public function log($id, $description, $start, $end) { - } - - /** - * @return \OCP\Diagnostics\IEvent[] - */ - public function getEvents() { - return array(); - } -} diff --git a/lib/private/Diagnostics/NullQueryLogger.php b/lib/private/Diagnostics/NullQueryLogger.php deleted file mode 100644 index 873f556f90..0000000000 --- a/lib/private/Diagnostics/NullQueryLogger.php +++ /dev/null @@ -1,46 +0,0 @@ - - * @author Robin Appelman - * - * @license AGPL-3.0 - * - * This code is free software: you can redistribute it and/or modify - * it under the terms of the GNU Affero General Public License, version 3, - * as published by the Free Software Foundation. - * - * This program is distributed in the hope that it will be useful, - * but WITHOUT ANY WARRANTY; without even the implied warranty of - * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the - * GNU Affero General Public License for more details. - * - * You should have received a copy of the GNU Affero General Public License, version 3, - * along with this program. If not, see - * - */ - -namespace OC\Diagnostics; - -use OCP\Diagnostics\IQueryLogger; - -class NullQueryLogger implements IQueryLogger { - /** - * @param string $sql - * @param array $params - * @param array $types - */ - public function startQuery($sql, array $params = null, array $types = null) { - } - - public function stopQuery() { - } - - /** - * @return \OCP\Diagnostics\IQuery[] - */ - public function getQueries() { - return array(); - } -} diff --git a/lib/private/Diagnostics/Query.php b/lib/private/Diagnostics/Query.php index 8ac2cc0eea..7b083ed41b 100644 --- a/lib/private/Diagnostics/Query.php +++ b/lib/private/Diagnostics/Query.php @@ -67,7 +67,14 @@ class Query implements IQuery { } /** - * @return int + * @return float + */ + public function getStart() { + return $this->start; + } + + /** + * @return float */ public function getDuration() { return $this->end - $this->start; diff --git a/lib/private/Diagnostics/QueryLogger.php b/lib/private/Diagnostics/QueryLogger.php index 5f2a061a91..54ce3542f4 100644 --- a/lib/private/Diagnostics/QueryLogger.php +++ b/lib/private/Diagnostics/QueryLogger.php @@ -3,7 +3,13 @@ * @copyright Copyright (c) 2016, ownCloud, Inc. * * @author Morris Jobke +<<<<<<< HEAD * @author Robin Appelman +======= + * @author Robin Appelman + * @author Thomas Müller + * @author Piotr Mrowczynski +>>>>>>> a5095447b7... Adjust query/event logging code in favour of more complex owncloud/diagnostics (#27643) * * @license AGPL-3.0 * @@ -46,12 +52,17 @@ class QueryLogger implements IQueryLogger { /** - * @param string $sql - * @param array $params - * @param array $types + * @var bool - Module needs to be activated by some app + */ + private $activated = false; + + /** + * @inheritdoc */ public function startQuery($sql, array $params = null, array $types = null) { - $this->activeQuery = new Query($sql, $params, microtime(true), $this->getStack()); + if ($this->activated) { + $this->activeQuery = new Query($sql, $params, microtime(true), $this->getStack()); + } } private function getStack() { @@ -62,8 +73,11 @@ class QueryLogger implements IQueryLogger { return $stack; } + /** + * @inheritdoc + */ public function stopQuery() { - if ($this->activeQuery) { + if ($this->activated && $this->activeQuery) { $this->activeQuery->end(microtime(true)); $this->queries[] = $this->activeQuery; $this->activeQuery = null; @@ -71,9 +85,16 @@ class QueryLogger implements IQueryLogger { } /** - * @return Query[] + * @inheritdoc */ public function getQueries() { return $this->queries->getData(); } + + /** + * @inheritdoc + */ + public function activate() { + $this->activated = true; + } } diff --git a/lib/private/Server.php b/lib/private/Server.php index 7724feb551..8c6fb8aab6 100644 --- a/lib/private/Server.php +++ b/lib/private/Server.php @@ -602,22 +602,23 @@ class Server extends ServerContainer implements IServerContainer { ); }); $this->registerAlias('HttpClientService', \OCP\Http\Client\IClientService::class); - $this->registerService(\OCP\Diagnostics\IEventLogger::class, function (Server $c) { + $eventLogger = new EventLogger(); if ($c->getSystemConfig()->getValue('debug', false)) { - return new EventLogger(); - } else { - return new NullEventLogger(); + // In debug mode, module is being activated by default + $eventLogger->activate(); } + return $eventLogger; }); $this->registerAlias('EventLogger', \OCP\Diagnostics\IEventLogger::class); $this->registerService(\OCP\Diagnostics\IQueryLogger::class, function (Server $c) { + $queryLogger = new QueryLogger(); if ($c->getSystemConfig()->getValue('debug', false)) { - return new QueryLogger(); - } else { - return new NullQueryLogger(); + // In debug mode, module is being activated by default + $queryLogger->activate(); } + return $queryLogger; }); $this->registerAlias('QueryLogger', \OCP\Diagnostics\IQueryLogger::class); diff --git a/lib/private/legacy/db/statementwrapper.php b/lib/private/legacy/db/statementwrapper.php index dedaf2d8ce..53f7b484d0 100644 --- a/lib/private/legacy/db/statementwrapper.php +++ b/lib/private/legacy/db/statementwrapper.php @@ -64,14 +64,7 @@ class OC_DB_StatementWrapper { * @param array $input * @return \OC_DB_StatementWrapper|int */ - public function execute($input=array()) { - if(\OC::$server->getSystemConfig()->getValue( "log_query", false)) { - $backTrace = debug_backtrace(); - $class = $backTrace[1]['class'] . ':' . $backTrace[1]['function']; - $file = substr($backTrace[0]['file'], strlen(\OC::$SERVERROOT)) . ':' . $backTrace[0]['line']; - $params_str = str_replace("\n", " ", var_export($input, true)); - \OCP\Util::writeLog('core', "DB execute with arguments : $params_str in $class; $file", \OCP\Util::DEBUG); - } + public function execute($input= []) { $this->lastArguments = $input; if (count($input) > 0) { $result = $this->statement->execute($input); diff --git a/lib/public/Diagnostics/IEventLogger.php b/lib/public/Diagnostics/IEventLogger.php index 517a131d43..4c2ae9e3b2 100644 --- a/lib/public/Diagnostics/IEventLogger.php +++ b/lib/public/Diagnostics/IEventLogger.php @@ -3,7 +3,12 @@ * @copyright Copyright (c) 2016, ownCloud, Inc. * * @author Morris Jobke +<<<<<<< HEAD * @author Robin Appelman +======= + * @author Robin Appelman + * @author Piotr Mrowczynski +>>>>>>> a5095447b7... Adjust query/event logging code in favour of more complex owncloud/diagnostics (#27643) * * @license AGPL-3.0 * @@ -31,7 +36,7 @@ namespace OCP\Diagnostics; */ interface IEventLogger { /** - * Mark the start of an event + * Mark the start of an event setting its ID $id and providing event description $description. * * @param string $id * @param string $description @@ -40,7 +45,9 @@ interface IEventLogger { public function start($id, $description); /** - * Mark the end of an event + * Mark the end of an event with specific ID $id, marked by start() method. + * Ending event should store \OCP\Diagnostics\IEvent to + * be returned with getEvents() method. * * @param string $id * @since 8.0.0 @@ -48,6 +55,11 @@ interface IEventLogger { public function end($id); /** + * Mark the start and the end of an event with specific ID $id and description $description, + * explicitly marking start and end of the event, represented by $start and $end timestamps. + * Logging event should store \OCP\Diagnostics\IEvent to + * be returned with getEvents() method. + * * @param string $id * @param string $description * @param float $start @@ -57,8 +69,21 @@ interface IEventLogger { public function log($id, $description, $start, $end); /** + * This method should return all \OCP\Diagnostics\IEvent objects stored using + * start()/end() or log() methods + * * @return \OCP\Diagnostics\IEvent[] * @since 8.0.0 */ public function getEvents(); + + /** + * Activate the module for the duration of the request. Deactivated module + * does not create and store \OCP\Diagnostics\IEvent objects. + * Only activated module should create and store objects to be + * returned with getEvents() call. + * + * @since 12.0.0 + */ + public function activate(); } diff --git a/lib/public/Diagnostics/IQuery.php b/lib/public/Diagnostics/IQuery.php index 7f26bd7f1b..ceaee191b3 100644 --- a/lib/public/Diagnostics/IQuery.php +++ b/lib/public/Diagnostics/IQuery.php @@ -59,4 +59,9 @@ interface IQuery { * @since 11.0.0 */ public function getStacktrace(); + /** + * @return array + * @since 12.0.0 + */ + public function getStart(); } diff --git a/lib/public/Diagnostics/IQueryLogger.php b/lib/public/Diagnostics/IQueryLogger.php index 58ea78795e..3ab491a275 100644 --- a/lib/public/Diagnostics/IQueryLogger.php +++ b/lib/public/Diagnostics/IQueryLogger.php @@ -3,7 +3,12 @@ * @copyright Copyright (c) 2016, ownCloud, Inc. * * @author Morris Jobke +<<<<<<< HEAD * @author Robin Appelman +======= + * @author Robin Appelman + * @author Piotr Mrowczynski +>>>>>>> a5095447b7... Adjust query/event logging code in favour of more complex owncloud/diagnostics (#27643) * * @license AGPL-3.0 * @@ -33,6 +38,10 @@ use Doctrine\DBAL\Logging\SQLLogger; */ interface IQueryLogger extends SQLLogger { /** + * 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 + * query is finished finalized with stopQuery() method. + * * @param string $sql * @param array $params * @param array $types @@ -41,14 +50,30 @@ interface IQueryLogger extends SQLLogger { public function startQuery($sql, array $params = null, array $types = null); /** + * 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(); /** + * This method should return all \OCP\Diagnostics\IQuery objects stored using + * startQuery()/stopQuery() methods. + * * @return \OCP\Diagnostics\IQuery[] * @since 8.0.0 */ public function getQueries(); + + /** + * Activate the module for the duration of the request. Deactivated module + * does not create and store \OCP\Diagnostics\IQuery objects. + * Only activated module should create and store objects to be + * returned with getQueries() call. + * + * @since 12.0.0 + */ + public function activate(); } diff --git a/tests/lib/Diagnostics/EventLoggerTest.php b/tests/lib/Diagnostics/EventLoggerTest.php new file mode 100644 index 0000000000..2d0c82ba72 --- /dev/null +++ b/tests/lib/Diagnostics/EventLoggerTest.php @@ -0,0 +1,66 @@ + + * + * @copyright Copyright (c) 2017, ownCloud GmbH + * @license AGPL-3.0 + * + * This code is free software: you can redistribute it and/or modify + * it under the terms of the GNU Affero General Public License, version 3, + * as published by the Free Software Foundation. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU Affero General Public License for more details. + * + * You should have received a copy of the GNU Affero General Public License, version 3, + * along with this program. If not, see + * + */ + +namespace Test\Diagnostics; + +use OC\Diagnostics\EventLogger; +use Test\TestCase; + +class EventLoggerTest extends TestCase { + + /** @var \OC\Diagnostics\EventLogger */ + private $logger; + + public function setUp() { + parent::setUp(); + + $this->logger = new EventLogger(); + } + + public function testQueryLogger() { + // Module is not activated and this should not be logged + $this->logger->start("test1", "testevent1"); + $this->logger->end("test1"); + $this->logger->log("test2", "testevent2", microtime(true), microtime(true)); + $events = $this->logger->getEvents(); + $this->assertSame(0, sizeof($events)); + + // Activate module and log some query + $this->logger->activate(); + + // start one event + $this->logger->start("test3", "testevent3"); + + // force log of another event + $this->logger->log("test4", "testevent4", microtime(true), microtime(true)); + + // log started event + $this->logger->end("test3"); + + $events = $this->logger->getEvents(); + $this->assertSame("test4", $events['test4']->getId()); + $this->assertSame("testevent4", $events['test4']->getDescription()); + $this->assertSame("test3", $events['test3']->getId()); + $this->assertSame("testevent3", $events['test3']->getDescription()); + $this->assertSame(2, sizeof($events)); + + } +} diff --git a/tests/lib/Diagnostics/QueryLoggerTest.php b/tests/lib/Diagnostics/QueryLoggerTest.php new file mode 100644 index 0000000000..99de60ed8e --- /dev/null +++ b/tests/lib/Diagnostics/QueryLoggerTest.php @@ -0,0 +1,54 @@ + + * + * @copyright Copyright (c) 2017, ownCloud GmbH + * @license AGPL-3.0 + * + * This code is free software: you can redistribute it and/or modify + * it under the terms of the GNU Affero General Public License, version 3, + * as published by the Free Software Foundation. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU Affero General Public License for more details. + * + * You should have received a copy of the GNU Affero General Public License, version 3, + * along with this program. If not, see + * + */ + +namespace Test\Diagnostics; + +use OC\Diagnostics\QueryLogger; +use Test\TestCase; + +class QueryLoggerTest extends TestCase { + + /** @var \OC\Diagnostics\QueryLogger */ + private $logger; + + public function setUp() { + parent::setUp(); + + $this->logger = new QueryLogger(); + } + + public function testQueryLogger() { + // Module is not activated and this should not be logged + $this->logger->startQuery("SELECT", ["testuser", "count"], ["string", "int"]); + $this->logger->stopQuery(); + $queries = $this->logger->getQueries(); + $this->assertSame(0, sizeof($queries)); + + // Activate module and log some query + $this->logger->activate(); + $this->logger->startQuery("SELECT", ["testuser", "count"], ["string", "int"]); + $this->logger->stopQuery(); + + $queries = $this->logger->getQueries(); + $this->assertSame(1, sizeof($queries)); + + } +}