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

13 files changed, 254 insertions, 137 deletions

diff --git a/lib/private/DB/Connection.php b/lib/private/DB/Connection.php
index 9e116712642..6b56ae8ad5c 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 5abaae3f1dd..846be7efc5b 100644
--- a/lib/private/Diagnostics/EventLogger.php
+++ b/lib/private/Diagnostics/EventLogger.php
@@ -4,6 +4,8 @@
  *
  * @author Morris Jobke <hey@morrisjobke.de>
  * @author Robin Appelman <robin@icewind.nl>
+ * @author Thomas Müller <thomas.mueller@tmit.eu>
+ * @author Piotr Mrowczynski <piotr@owncloud.com>
  *
  * @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 9fe7461eb45..00000000000
--- a/lib/private/Diagnostics/NullEventLogger.php
+++ /dev/null
@@ -1,58 +0,0 @@
-<?php
-/**
- * @copyright Copyright (c) 2016, ownCloud, Inc.
- *
- * @author Morris Jobke <hey@morrisjobke.de>
- * @author Robin Appelman <robin@icewind.nl>
- *
- * @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 <http://www.gnu.org/licenses/>
- *
- */
-
-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 873f556f90e..00000000000
--- a/lib/private/Diagnostics/NullQueryLogger.php
+++ /dev/null
@@ -1,46 +0,0 @@
-<?php
-/**
- * @copyright Copyright (c) 2016, ownCloud, Inc.
- *
- * @author Morris Jobke <hey@morrisjobke.de>
- * @author Robin Appelman <robin@icewind.nl>
- *
- * @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 <http://www.gnu.org/licenses/>
- *
- */
-
-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 8ac2cc0eeac..7b083ed41b7 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 5f2a061a910..54ce3542f49 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 <hey@morrisjobke.de>
+<<<<<<< HEAD
  * @author Robin Appelman <robin@icewind.nl>
+=======
+ * @author Robin Appelman <icewind@owncloud.com>
+ * @author Thomas Müller <thomas.mueller@tmit.eu>
+ * @author Piotr Mrowczynski <piotr@owncloud.com>
+>>>>>>> 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 7724feb551b..8c6fb8aab64 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 dedaf2d8cef..53f7b484d04 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 517a131d436..4c2ae9e3b2c 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 <hey@morrisjobke.de>
+<<<<<<< HEAD
  * @author Robin Appelman <robin@icewind.nl>
+=======
+ * @author Robin Appelman <icewind@owncloud.com>
+ * @author Piotr Mrowczynski <piotr@owncloud.com>
+>>>>>>> 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 7f26bd7f1b8..ceaee191b39 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 58ea78795e2..3ab491a2751 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 <hey@morrisjobke.de>
+<<<<<<< HEAD
  * @author Robin Appelman <robin@icewind.nl>
+=======
+ * @author Robin Appelman <icewind@owncloud.com>
+ * @author Piotr Mrowczynski <piotr@owncloud.com>
+>>>>>>> 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 00000000000..2d0c82ba72e
--- /dev/null
+++ b/tests/lib/Diagnostics/EventLoggerTest.php
@@ -0,0 +1,66 @@
+<?php
+/**
+ * @author Piotr Mrowczynski <piotr@owncloud.com>
+ *
+ * @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 <http://www.gnu.org/licenses/>
+ *
+ */
+
+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 00000000000..99de60ed8e4
--- /dev/null
+++ b/tests/lib/Diagnostics/QueryLoggerTest.php
@@ -0,0 +1,54 @@
+<?php
+/**
+ * @author Piotr Mrowczynski <piotr@owncloud.com>
+ *
+ * @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 <http://www.gnu.org/licenses/>
+ *
+ */
+
+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));
+
+	}
+}