DBAL-39 - Changed SQLLogger again, the recent change disallows to log…

… a failed query, however adding a lastexecuted query would add additional overhead (last params and types would be needed to). So now each logger has a startQuery() and a stopQuery() method. Additionally the logger now gets passed the array of types.
doctrine · Aug 15, 2010 · 432e2f7 · 432e2f7
1 parent a47bf85
commit 432e2f7
Show file tree

Hide file tree

Showing 6 changed files with 62 additions and 16 deletions.
diff --git a/lib/Doctrine/DBAL/Connection.php b/lib/Doctrine/DBAL/Connection.php
@@ -555,7 +555,7 @@ public function executeQuery($query, array $params = array(), $types = array())
 
         $hasLogger = $this->_config->getSQLLogger() !== null;
         if ($hasLogger) {
-            $queryStart = microtime(true);
+            $this->_config->getSQLLogger()->startQuery($query, $params, $types);
         }
 
         if ($params) {
@@ -571,7 +571,7 @@ public function executeQuery($query, array $params = array(), $types = array())
         }
 
         if ($hasLogger) {
-            $this->_config->getSQLLogger()->logSQL($query, $params, microtime(true) - $queryStart);
+            $this->_config->getSQLLogger()->stopQuery();
         }
 
         return $stmt;
@@ -634,7 +634,7 @@ public function executeUpdate($query, array $params = array(), array $types = ar
 
         $hasLogger = $this->_config->getSQLLogger() !== null;
         if ($hasLogger) {
-            $queryStart = microtime(true);
+            $this->_config->getSQLLogger()->startQuery($query, $params, $types);
         }
 
         if ($params) {
@@ -651,7 +651,7 @@ public function executeUpdate($query, array $params = array(), array $types = ar
         }
 
         if ($hasLogger) {
-            $this->_config->getSQLLogger()->logSQL($query, $params, microtime(true) - $queryStart);
+            $this->_config->getSQLLogger()->stopQuery();
         }
 
         return $result;

diff --git a/lib/Doctrine/DBAL/Logging/DebugStack.php b/lib/Doctrine/DBAL/Logging/DebugStack.php
@@ -41,14 +41,25 @@ class DebugStack implements SQLLogger
     /** @var boolean $enabled If Debug Stack is enabled (log queries) or not. */
     public $enabled = true;
 
+    public $start = null;
+
     /**
      * {@inheritdoc}
      */
-    public function logSQL($sql, array $params = null, $executionMS = null)
+    public function startQuery($sql, array $params = null, array $types = null)
     {
         if ($this->enabled) {
-            $this->queries[] = array('sql' => $sql, 'params' => $params, 'executionMS' => $executionMS);
+            $this->start = microtime(true);
+            $this->queries[] = array('sql' => $sql, 'params' => $params, 'types' => $types, 'executionMS' => 0);
         }
     }
+
+    /**
+     * {@inheritdoc}
+     */
+    public function stopQuery()
+    {
+        $this->queries[(count($this->queries)-1)]['executionMS'] = microtime(true) - $this->start;
+    }
 }
 
diff --git a/lib/Doctrine/DBAL/Logging/EchoSQLLogger.php b/lib/Doctrine/DBAL/Logging/EchoSQLLogger.php
@@ -38,14 +38,24 @@ class EchoSQLLogger implements SQLLogger
     /**
      * {@inheritdoc}
      */
-    public function logSQL($sql, array $params = null, $executionMS = null)
+    public function startQuery($sql, array $params = null, array $types = null)
     {
     	echo $sql . PHP_EOL;
 
         if ($params) {
             var_dump($params);
     	}
 
-        echo "Took " . number_format($executionMS, 4) . " seconds" . PHP_EOL;
+        if ($types) {
+            var_dump($types);
+        }
+    }
+
+    /**
+     * {@inheritdoc}
+     */
+    public function stopQuery()
+    {
+
     }
 }
diff --git a/lib/Doctrine/DBAL/Logging/SQLLogger.php b/lib/Doctrine/DBAL/Logging/SQLLogger.php
@@ -43,5 +43,12 @@ interface SQLLogger
      * @param float $executionMS The microtime difference it took to execute this query.
      * @return void
      */
-    function logSQL($sql, array $params = null, $executionMS = null);
+    public function startQuery($sql, array $params = null, array $types = null);
+
+    /**
+     * Mark the last started query as stopped. This can be used for timing of queries.
+     *
+     * @return void
+     */
+    public function stopQuery();
 }
diff --git a/lib/Doctrine/DBAL/Statement.php b/lib/Doctrine/DBAL/Statement.php
@@ -125,13 +125,13 @@ public function execute($params = null)
     {
         $hasLogger = $this->_conn->getConfiguration()->getSQLLogger();
         if ($hasLogger) {
-            $queryStart = microtime(true);
+            $this->_conn->getConfiguration()->getSQLLogger()->startQuery($this->_sql, $this->_params);
         }
 
         $stmt = $this->_stmt->execute($params);
 
         if ($hasLogger) {
-            $this->_conn->getConfiguration()->getSQLLogger()->logSQL($this->_sql, $this->_params, microtime(true) - $queryStart);
+            $this->_conn->getConfiguration()->getSQLLogger()->stopQuery();
         }
         $this->_params = array();
         return $stmt;

diff --git a/tests/Doctrine/Tests/DBAL/Functional/LoggingTest.php b/tests/Doctrine/Tests/DBAL/Functional/LoggingTest.php
@@ -11,21 +11,39 @@ public function testLogExecuteQuery()
         $sql = $this->_conn->getDatabasePlatform()->getDummySelectSQL();
 
         $logMock = $this->getMock('Doctrine\DBAL\Logging\SQLLogger');
-        $logMock->expects($this->once())
-                ->method('logSQL')
-                ->with($this->equalTo($sql), $this->equalTo(array()), $this->isType('float'));
+        $logMock->expects($this->at(0))
+                ->method('startQuery')
+                ->with($this->equalTo($sql), $this->equalTo(array()), $this->equalTo(array()));
+        $logMock->expects($this->at(1))
+                ->method('stopQuery');
         $this->_conn->getConfiguration()->setSQLLogger($logMock);
         $this->_conn->executeQuery($sql, array());
     }
 
+    public function testLogExecuteUpdate()
+    {
+        $sql = $this->_conn->getDatabasePlatform()->getDummySelectSQL();
+
+        $logMock = $this->getMock('Doctrine\DBAL\Logging\SQLLogger');
+        $logMock->expects($this->at(0))
+                ->method('startQuery')
+                ->with($this->equalTo($sql), $this->equalTo(array()), $this->equalTo(array()));
+        $logMock->expects($this->at(1))
+                ->method('stopQuery');
+        $this->_conn->getConfiguration()->setSQLLogger($logMock);
+        $this->_conn->executeUpdate($sql, array());
+    }
+
     public function testLogPrepareExecute()
     {
         $sql = $this->_conn->getDatabasePlatform()->getDummySelectSQL();
 
         $logMock = $this->getMock('Doctrine\DBAL\Logging\SQLLogger');
         $logMock->expects($this->once())
-                ->method('logSQL')
-                ->with($this->equalTo($sql), $this->equalTo(array()), $this->isType('float'));
+                ->method('startQuery')
+                ->with($this->equalTo($sql), $this->equalTo(array()));
+        $logMock->expects($this->at(1))
+                ->method('stopQuery');
         $this->_conn->getConfiguration()->setSQLLogger($logMock);
 
         $stmt = $this->_conn->prepare($sql);