DBAL-39 - Changed SQLLogger again, the recent change disallows to log a failed...

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.

lib/Doctrine/DBAL/Connection.php

@@ -555,7 +555,7 @@ class Connection implements DriverConnection
 
         $hasLogger = $this->_config->getSQLLogger() !== null;
         if ($hasLogger) {
-            $queryStart = microtime(true);
+            $this->_config->getSQLLogger()->startQuery($query, $params, $types);
         }
 
         if ($params) {
@@ -571,7 +571,7 @@ class Connection implements DriverConnection
         }
 
         if ($hasLogger) {
-            $this->_config->getSQLLogger()->logSQL($query, $params, microtime(true) - $queryStart);
+            $this->_config->getSQLLogger()->stopQuery();
         }
 
         return $stmt;
@@ -634,7 +634,7 @@ class Connection implements DriverConnection
 
         $hasLogger = $this->_config->getSQLLogger() !== null;
         if ($hasLogger) {
-            $queryStart = microtime(true);
+            $this->_config->getSQLLogger()->startQuery($query, $params, $types);
         }
 
         if ($params) {
@@ -651,7 +651,7 @@ class Connection implements DriverConnection
         }
 
         if ($hasLogger) {
-            $this->_config->getSQLLogger()->logSQL($query, $params, microtime(true) - $queryStart);
+            $this->_config->getSQLLogger()->stopQuery();
         }
 
         return $result;

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;
+    }
 }
 

lib/Doctrine/DBAL/Logging/EchoSQLLogger.php

@@ -38,7 +38,7 @@ 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;
 
@@ -46,6 +46,16 @@ class EchoSQLLogger implements SQLLogger
             var_dump($params);
     	}
 
-        echo "Took " . number_format($executionMS, 4) . " seconds" . PHP_EOL;
+        if ($types) {
+            var_dump($types);
+        }
+    }
+
+    /**
+     * {@inheritdoc}
+     */
+    public function stopQuery()
+    {
+
     }
 }
\ No newline at end of file

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();
 }
\ No newline at end of file

lib/Doctrine/DBAL/Statement.php

@@ -125,13 +125,13 @@ class Statement implements DriverStatement
     {
         $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;

tests/Doctrine/Tests/DBAL/Functional/LoggingTest.php

@@ -11,21 +11,39 @@ class LoggingTest extends \Doctrine\Tests\DbalFunctionalTestCase
         $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);