From bcd597557505013913e06e1eb6d7071918c529c7 Mon Sep 17 00:00:00 2001 From: Pierre du Plessis Date: Wed, 5 Nov 2014 23:49:36 +0200 Subject: [PATCH] Added TraceLogger to get backtrace for executed queries --- lib/Doctrine/DBAL/Logging/TraceLogger.php | 125 ++++++++++++++++++ .../Tests/DBAL/Logging/TraceLoggerTest.php | 65 +++++++++ 2 files changed, 190 insertions(+) create mode 100644 lib/Doctrine/DBAL/Logging/TraceLogger.php create mode 100644 tests/Doctrine/Tests/DBAL/Logging/TraceLoggerTest.php diff --git a/lib/Doctrine/DBAL/Logging/TraceLogger.php b/lib/Doctrine/DBAL/Logging/TraceLogger.php new file mode 100644 index 00000000000..8327952dff2 --- /dev/null +++ b/lib/Doctrine/DBAL/Logging/TraceLogger.php @@ -0,0 +1,125 @@ +. + */ + +namespace Doctrine\DBAL\Logging; + +/** + * Includes backtrace and executed SQLs in a Debug Stack. + * + * @link www.doctrine-project.org + * @author Pierre du Plessis + */ +class TraceLogger implements SQLLogger +{ + /** + * Executed SQL queries. + * + * @var array + */ + public $queries = array(); + + /** + * If the logger is enabled (log queries) or not. + * + * @var boolean + */ + public $enabled = true; + + /** + * @var float|null + */ + public $start = null; + + /** + * @var integer + */ + public $currentQuery = 0; + + /** + * {@inheritdoc} + */ + public function startQuery($sql, array $params = null, array $types = null) + { + if ($this->enabled) { + $backtrace = $this->getBactrace(); + + $this->start = microtime(true); + $this->queries[++$this->currentQuery] = array('sql' => $sql, 'params' => $params, 'types' => $types, 'executionMS' => 0, 'trace' => $backtrace); + } + } + + /** + * {@inheritdoc} + */ + public function stopQuery() + { + if ($this->enabled) { + $this->queries[$this->currentQuery]['executionMS'] = microtime(true) - $this->start; + } + } + + private function getBactrace() + { + $backtrace = debug_backtrace(DEBUG_BACKTRACE_PROVIDE_OBJECT | DEBUG_BACKTRACE_IGNORE_ARGS); + + foreach ($backtrace as $key => $debug) { + if (!$this->isInternalClass($debug['class'])) { + $trace = array_slice($backtrace, $key - 1, 10); + + return $this->formatTrace($trace); + } + } + + return array(); + } + + private function formatTrace(array $trace) + { + $backtrace = array(); + + foreach ($trace as $index => $line) { + $backtrace[$index] = ''; + + if (isset($trace[$index + 1]['class'])) { + $backtrace[$index] .= $trace[$index + 1]['class']; + } else { + $backtrace[$index] .= get_class($line['object']); + } + + $backtrace[$index] .= '::'; + + if (isset($trace[$index + 1])) { + $backtrace[$index] .= $trace[$index + 1]['function']; + } else { + $backtrace[$index] .= $line['function']; + } + + if (isset($line['line'])) { + $backtrace[$index] .= ' (L' . $line['line'] . ')'; + } + } + + return $backtrace; + } + + private function isInternalClass(&$class) + { + return substr($class, 0, strpos($class, '\\')) === 'Doctrine'; + } +} diff --git a/tests/Doctrine/Tests/DBAL/Logging/TraceLoggerTest.php b/tests/Doctrine/Tests/DBAL/Logging/TraceLoggerTest.php new file mode 100644 index 00000000000..1dc07b2f8ee --- /dev/null +++ b/tests/Doctrine/Tests/DBAL/Logging/TraceLoggerTest.php @@ -0,0 +1,65 @@ +logger = new \Doctrine\DBAL\Logging\TraceLogger(); + } + + public function tearDown() + { + unset($this->logger); + } + + public function testLoggedQuery() + { + $this->logger->startQuery('SELECT column FROM table'); + + $this->assertEquals( + array( + 1 => array( + 'sql' => 'SELECT column FROM table', + 'params' => null, + 'types' => null, + 'executionMS' => 0, + 'trace' => array( + "ReflectionMethod::invokeArgs", + "PHPUnit_Framework_TestCase::runTest (L905)", + "PHPUnit_Framework_TestCase::runBare (L775)", + "PHPUnit_Framework_TestResult::run (L643)", + "PHPUnit_Framework_TestCase::run (L711)", + "PHPUnit_Framework_TestSuite::run (L751)", + "PHPUnit_Framework_TestSuite::run (L751)", + "PHPUnit_TextUI_TestRunner::doRun (L423)", + "PHPUnit_TextUI_Command::run (L186)", + "PHPUnit_TextUI_Command::run (L138)" + ) + ), + ), + $this->logger->queries + ); + + $this->logger->stopQuery(); + $this->assertGreaterThan(0, $this->logger->queries[1]['executionMS']); + } + + public function testLoggedQueryDisabled() + { + $this->logger->enabled = false; + $this->logger->startQuery('SELECT column FROM table'); + $this->assertEquals(array(), $this->logger->queries); + + $this->logger->stopQuery(); + $this->assertEquals(array(), $this->logger->queries); + } +}