Issue #2867788 by mondrake, daffie, dawehner, alexpott, larowlan:... (97bac4f1) · Commits · project / drupal

core/lib/Drupal/Core/Database/Log.php

+62 −17

Original line number	Diff line number	Diff line
		@@ -38,6 +38,13 @@ class Log {
		*/
		protected $connectionKey = 'default';

		/**
		* The PHP namespace of the database driver that this object is logging.
		*
		* @var string
		*/
		protected $driverNamespace;

		/**
		* Constructor.
		*
		@@ -124,11 +131,13 @@ public function log(StatementInterface $statement, $args, $time) {
		/**
		* Determine the routine that called this query.
		*
		* We define "the routine that called this query" as the first entry in
		* the call stack that is not inside the includes/Drupal/Database directory
		* and does have a file (which excludes call_user_func_array(), anonymous
		* functions and similar). That makes the climbing logic very simple, and
		* handles the variable stack depth caused by the query builders.
		* Traversing the call stack from the very first call made during the
		* request, we define "the routine that called this query" as the last entry
		* in the call stack that is not any method called from the namespace of the
		* database driver, is not inside the Drupal\Core\Database namespace and does
		* have a file (which excludes call_user_func_array(), anonymous functions
		* and similar). That makes the climbing logic very simple, and handles the
		* variable stack depth caused by the query builders.
		*
		* See the @link http://php.net/debug_backtrace debug_backtrace() @endlink
		* function.
		@@ -141,26 +150,62 @@ public function log(StatementInterface $statement, $args, $time) {
		* database call itself.
		*/
		public function findCaller() {
		$stack = debug_backtrace();
		for ($i = 0, $stack_count = count($stack); $i < $stack_count; ++$i) {
		// If the call was made from a function, 'class' will be empty. It's
		// just easier to give it a default value than to try and integrate
		// that into the if statement below.
		if (empty($stack[$i + 1]['class'])) {
		$stack[$i + 1]['class'] = '';
		}
		if (strpos($stack[$i + 1]['class'], __NAMESPACE__) === FALSE && !empty($stack[$i]['file'])) {
		$stack[$i] += ['file' => '?', 'line' => '?', 'args' => []];
		$stack = $this->getDebugBacktrace();

		// Starting from the very first entry processed during the request, find
		// the first function call that can be identified as a call to a
		// method/function in the database layer.
		for ($n = count($stack) - 1; $n >= 0; $n--) {
		// If the call was made from a function, 'class' will be empty. We give
		// it a default empty string value in that case.
		$class = $stack[$n]['class'] ?? '';

		if (strpos($class, __NAMESPACE__, 0) === 0 \|\| strpos($class, $this->getDriverNamespace(), 0) === 0) {
		break;
		}
		}

		// Return the previous function call whose stack entry has a 'file' key,
		// that is, it is not a callback or a closure.
		for ($i = $n; $i < count($stack); $i++) {
		if (!empty($stack[$i]['file'])) {
		return [
		'file' => $stack[$i]['file'],
		'line' => $stack[$i]['line'],
		'function' => $stack[$i + 1]['function'],
		'class' => $stack[$i + 1]['class'],
		'type' => isset($stack[$i + 1]['type']) ? $stack[$i + 1]['type'] : NULL,
		'args' => $stack[$i + 1]['args'],
		'class' => $stack[$i + 1]['class'] ?? NULL,
		'type' => $stack[$i + 1]['type'] ?? NULL,
		'args' => $stack[$i + 1]['args'] ?? [],
		];
		}
		}
		}

		/**
		* Gets the namespace of the database driver.
		*
		* @return string\|null
		* Namespace of the database driver, or NULL if the connection is
		* missing.
		*/
		protected function getDriverNamespace() {
		if (!isset($this->driverNamespace)) {
		$this->driverNamespace = (new \ReflectionObject(Database::getConnection('default', $this->connectionKey)))->getNamespaceName();
		}
		return $this->driverNamespace;
		}

		/**
		* Gets the debug backtrace.
		*
		* Wraps the debug_backtrace function to allow mocking results in PHPUnit
		* tests.
		*
		* @return array[]
		* The debug backtrace.
		*/
		protected function getDebugBacktrace() {
		return debug_backtrace();
		}

		}

core/tests/Drupal/KernelTests/Core/Database/LoggingTest.php

+192 −0

Original line number	Diff line number	Diff line
		@@ -2,11 +2,14 @@

		namespace Drupal\KernelTests\Core\Database;

		use Drupal\Core\Database\Log;
		use Drupal\Core\Database\Database;

		/**
		* Tests the query logging facility.
		*
		* @coversDefaultClass \Drupal\Core\Database\Log
		*
		* @group Database
		*/
		class LoggingTest extends DatabaseTestBase {
		@@ -135,4 +138,193 @@ public function testGetLoggingWrongKey() {
		$this->assertEqual($result, [], 'The function getLog with a wrong key returns an empty array.');
		}

		/**
		* Tests that a log called by a custom database driver returns proper caller.
		*
		* @param string $driver_namespace
		* The driver namespace to be tested.
		* @param string $stack
		* A test debug_backtrace stack.
		* @param array $expected_entry
		* The expected stack entry.
		*
		* @covers ::findCaller
		*
		* @dataProvider providerContribDriverLog
		*/
		public function testContribDriverLog($driver_namespace, $stack, array $expected_entry) {
		$mock_builder = $this->getMockBuilder(Log::class);
		$log = $mock_builder
		->setMethods(['getDriverNamespace', 'getDebugBacktrace'])
		->getMock();
		$log->expects($this->any())
		->method('getDriverNamespace')
		->will($this->returnValue($driver_namespace));
		$log->expects($this->once())
		->method('getDebugBacktrace')
		->will($this->returnValue($stack));

		$result = $log->findCaller($stack);
		$this->assertEquals($expected_entry, $result);
		}

		/**
		* Provides data for the testContribDriverLog test.
		*
		* @return array[]
		* A associative array of simple arrays, each having the following elements:
		* - the contrib driver PHP namespace
		* - a test debug_backtrace stack
		* - the stack entry expected to be returned.
		*
		* @see ::testContribDriverLog()
		*/
		public function providerContribDriverLog() {
		$stack = [
		[
		'file' => '/var/www/core/lib/Drupal/Core/Database/Log.php',
		'line' => 125,
		'function' => 'findCaller',
		'class' => 'Drupal\\Core\\Database\\Log',
		'object' => 'test',
		'type' => '->',
		'args' => [
		0 => 'test',
		],
		],
		[
		'file' => '/var/www/libraries/drudbal/lib/Statement.php',
		'line' => 264,
		'function' => 'log',
		'class' => 'Drupal\\Core\\Database\\Log',
		'object' => 'test',
		'type' => '->',
		'args' => [
		0 => 'test',
		],
		],
		[
		'file' => '/var/www/libraries/drudbal/lib/Connection.php',
		'line' => 213,
		'function' => 'execute',
		'class' => 'Drupal\\Driver\\Database\\dbal\\Statement',
		'object' => 'test',
		'type' => '->',
		'args' => [
		0 => 'test',
		],
		],
		[
		'file' => '/var/www/core/tests/Drupal/KernelTests/Core/Database/LoggingTest.php',
		'line' => 23,
		'function' => 'query',
		'class' => 'Drupal\\Driver\\Database\\dbal\\Connection',
		'object' => 'test',
		'type' => '->',
		'args' => [
		0 => 'test',
		],
		],
		[
		'file' => '/var/www/vendor/phpunit/phpunit/src/Framework/TestCase.php',
		'line' => 1154,
		'function' => 'testEnableLogging',
		'class' => 'Drupal\\KernelTests\\Core\\Database\\LoggingTest',
		'object' => 'test',
		'type' => '->',
		'args' => [
		0 => 'test',
		],
		],
		[
		'file' => '/var/www/vendor/phpunit/phpunit/src/Framework/TestCase.php',
		'line' => 842,
		'function' => 'runTest',
		'class' => 'PHPUnit\\Framework\\TestCase',
		'object' => 'test',
		'type' => '->',
		'args' => [
		0 => 'test',
		],
		],
		[
		'file' => '/var/www/vendor/phpunit/phpunit/src/Framework/TestResult.php',
		'line' => 693,
		'function' => 'runBare',
		'class' => 'PHPUnit\\Framework\\TestCase',
		'object' => 'test',
		'type' => '->',
		'args' => [
		0 => 'test',
		],
		],
		[
		'file' => '/var/www/vendor/phpunit/phpunit/src/Framework/TestCase.php',
		'line' => 796,
		'function' => 'run',
		'class' => 'PHPUnit\\Framework\\TestResult',
		'object' => 'test',
		'type' => '->',
		'args' => [
		0 => 'test',
		],
		],
		[
		'file' => 'Standard input code',
		'line' => 57,
		'function' => 'run',
		'class' => 'PHPUnit\\Framework\\TestCase',
		'object' => 'test',
		'type' => '->',
		'args' => [
		0 => 'test',
		],
		],
		[
		'file' => 'Standard input code',
		'line' => 111,
		'function' => '__phpunit_run_isolated_test',
		'args' => [
		0 => 'test',
		],
		],
		];

		return [
		// Test that if the driver namespace is in the stack trace, the first
		// non-database entry is returned.
		'contrib driver namespace' => [
		'Drupal\\Driver\\Database\\dbal',
		$stack,
		[
		'class' => 'Drupal\\KernelTests\\Core\\Database\\LoggingTest',
		'function' => 'testEnableLogging',
		'file' => '/var/www/core/tests/Drupal/KernelTests/Core/Database/LoggingTest.php',
		'line' => 23,
		'type' => '->',
		'args' => [
		0 => 'test',
		],
		],
		],
		// Extreme case, should not happen at normal runtime - if the driver
		// namespace is not in the stack trace, the first entry to a method
		// in core database namespace is returned.
		'missing driver namespace' => [
		'Drupal\\Driver\\Database\\fake',
		$stack,
		[
		'class' => 'Drupal\\Driver\\Database\\dbal\\Statement',
		'function' => 'execute',
		'file' => '/var/www/libraries/drudbal/lib/Statement.php',
		'line' => 264,
		'type' => '->',
		'args' => [
		0 => 'test',
		],
		],
		],
		];
		}

		}