[FEATURE] Extend IntrospectionProcessor to log full Backtrace 96/31296/9
authorSascha Egerer <sascha.egerer@dkd.de>
Wed, 2 Jul 2014 17:00:16 +0000 (19:00 +0200)
committerChristian Kuhn <lolli@schwarzbu.ch>
Fri, 25 Jul 2014 11:57:36 +0000 (13:57 +0200)
Extend the introspection processor so it can add
a full backtrace instead of only the last item
of the backtrace.

Also adds an option to shift a given amount of
levels from the backtrace.

Resolves: #60064
Documentation: #60074
Releases: 6.3
Change-Id: Ieb5d1e8ca11fdfd649d18d7751ebb0f770e60ef5
Reviewed-on: http://review.typo3.org/31296
Reviewed-by: Steffen Müller <typo3@t3node.com>
Tested-by: Steffen Müller <typo3@t3node.com>
Reviewed-by: Christian Kuhn <lolli@schwarzbu.ch>
Tested-by: Christian Kuhn <lolli@schwarzbu.ch>
typo3/sysext/core/Classes/Log/Processor/IntrospectionProcessor.php
typo3/sysext/core/Tests/Unit/Log/Processor/IntrospectionProcessorTest.php [new file with mode: 0644]
typo3/sysext/core/Tests/Unit/Log/Processor/IntrospectionTest.php [deleted file]

index d97e75c..1fc76cd 100644 (file)
@@ -13,6 +13,7 @@ namespace TYPO3\CMS\Core\Log\Processor;
  *
  * The TYPO3 project - inspiring people to share!
  */
+
 /**
  * Introspection processor to automatically add where the log record came from.
  *
@@ -21,6 +22,58 @@ namespace TYPO3\CMS\Core\Log\Processor;
 class IntrospectionProcessor extends \TYPO3\CMS\Core\Log\Processor\AbstractProcessor {
 
        /**
+        * Add the full backtrace to the log entry or
+        * just the last entry of the backtrace
+        *
+        * @var boolean
+        */
+       protected $appendFullBackTrace = FALSE;
+
+       /**
+        * Number of entries to shift from the backtrace
+        *
+        * @var int
+        */
+       protected $shiftBackTraceLevel = 0;
+
+       /**
+        * Temporary storage of the preceding backtrace line number
+        *
+        * @var string
+        */
+       private $precedingBacktraceLine = '';
+
+       /**
+        * Temporary storage of the preceding backtrace file
+        *
+        * @var string
+        */
+       private $precedingBacktraceFile = '';
+
+       /**
+        * Set the number of levels to be shift from the backtrace
+        *
+        * @param int $shiftBackTraceLevel Numbers of levels to shift
+        * @return \TYPO3\CMS\Core\Log\Writer\AbstractWriter
+        */
+       public function setShiftBackTraceLevel($shiftBackTraceLevel) {
+               $this->shiftBackTraceLevel = (int) $shiftBackTraceLevel;
+               return $this;
+       }
+
+       /**
+        * Set if the full backtrace should be added to the log or just the last item
+        *
+        * @param boolean $appendFullBackTrace If the full backtrace should be added
+        * @return \TYPO3\CMS\Core\Log\Writer\AbstractWriter
+        */
+       public function setAppendFullBackTrace($appendFullBackTrace) {
+               $this->appendFullBackTrace = (bool) $appendFullBackTrace;
+               return $this;
+       }
+
+
+       /**
         * Add debug backtrace information to logRecord
         * It adds: filepath, line number, class and function name
         *
@@ -29,25 +82,77 @@ class IntrospectionProcessor extends \TYPO3\CMS\Core\Log\Processor\AbstractProce
         * @see debug_backtrace()
         */
        public function processLogRecord(\TYPO3\CMS\Core\Log\LogRecord $logRecord) {
-               $trace = debug_backtrace();
-               // skip first since it's always the current method
-               array_shift($trace);
-               // the call_user_func call is also skipped
-               array_shift($trace);
+               $trace = $this->getDebugBacktrace();
+
                // skip TYPO3\CMS\Core\Log classes
-               // @TODO: Check, if this still works. This was 't3lib_log_' before namespace switch.
-               $i = 0;
-               while (isset($trace[$i]['class']) && FALSE !== strpos($trace[$i]['class'], 'TYPO3\CMS\Core\Log')) {
-                       $i++;
+               foreach ($trace as $traceEntry) {
+                       if (isset($traceEntry['class']) && FALSE !== strpos($traceEntry['class'], 'TYPO3\CMS\Core\Log')) {
+                               $trace = $this->shiftBacktraceLevel($trace);
+                       } else {
+                               break;
+                       }
+               }
+
+               // shift a given number of entries from the trace
+               for($i = 0; $i < $this->shiftBackTraceLevel; $i++) {
+                       // shift only if afterwards there is at least one entry left after.
+                       if (count($trace) > 1) {
+                               $trace = $this->shiftBacktraceLevel($trace);
+                       }
+               }
+
+               if ($this->appendFullBackTrace) {
+                       // Add the line and file of the last entry that has these information
+                       // to the first backtrace entry if it does not have this information.
+                       // This is required in case we have shifted entries and the first entry
+                       // is now a call_user_func that does not contain the line and file information.
+                       if (!isset($trace[0]['line'])) {
+                               $trace[0] = array('line' => $this->precedingBacktraceLine) + $trace[0];
+                       }
+                       if (!isset($trace[0]['file'])) {
+                               $trace[0] = array('file' => $this->precedingBacktraceFile) + $trace[0];
+                       }
+
+                       $logRecord->addData(array(
+                               'backtrace' => $trace
+                       ));
+               } else {
+                       $logRecord->addData(array(
+                               'file' => isset($trace[0]['file']) ? $trace[0]['file'] : NULL,
+                               'line' => isset($trace[0]['line']) ? $trace[0]['line'] : NULL,
+                               'class' => isset($trace[0]['class']) ? $trace[0]['class'] : NULL,
+                               'function' => isset($trace[0]['function']) ? $trace[0]['function'] : NULL
+                       ));
                }
-               // we should have the call source now
-               $logRecord->addData(array(
-                       'file' => isset($trace[$i]['file']) ? $trace[$i]['file'] : NULL,
-                       'line' => isset($trace[$i]['line']) ? $trace[$i]['line'] : NULL,
-                       'class' => isset($trace[$i]['class']) ? $trace[$i]['class'] : NULL,
-                       'function' => isset($trace[$i]['function']) ? $trace[$i]['function'] : NULL
-               ));
+
                return $logRecord;
        }
 
+       /**
+        * Shift the first item from the backtrace
+        *
+        * @param array $backtrace
+        * @return array
+        */
+       protected function shiftBacktraceLevel(array $backtrace) {
+               if (isset($backtrace[0]['file'])) {
+                       $this->precedingBacktraceFile = $backtrace[0]['file'];
+               }
+               if (isset($backtrace[0]['line'])) {
+                       $this->precedingBacktraceLine = $backtrace[0]['line'];
+               }
+               array_shift($backtrace);
+
+               return $backtrace;
+       }
+
+       /**
+        * Get the debug backtrace
+        *
+        * @return array
+        */
+       protected function getDebugBacktrace() {
+               return debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);
+       }
+
 }
diff --git a/typo3/sysext/core/Tests/Unit/Log/Processor/IntrospectionProcessorTest.php b/typo3/sysext/core/Tests/Unit/Log/Processor/IntrospectionProcessorTest.php
new file mode 100644 (file)
index 0000000..de25882
--- /dev/null
@@ -0,0 +1,174 @@
+<?php
+namespace TYPO3\CMS\Core\Tests\Unit\Log\Processor;
+
+/**
+ * This file is part of the TYPO3 CMS project.
+ *
+ * It is free software; you can redistribute it and/or modify it under
+ * the terms of the GNU General Public License, either version 2
+ * of the License, or any later version.
+ *
+ * For the full copyright and license information, please read the
+ * LICENSE.txt file that was distributed with this source code.
+ *
+ * The TYPO3 project - inspiring people to share!
+ */
+
+/**
+ * Test case
+ *
+ * @author Steffen Müller <typo3@t3node.com>
+ */
+class IntrospectionProcessorTest extends \TYPO3\CMS\Core\Tests\UnitTestCase {
+
+       /**
+        * @var \PHPUnit_Framework_MockObject_MockObject|\TYPO3\CMS\Core\Log\Processor\IntrospectionProcessor
+        */
+       protected $processor;
+
+       /**
+        * A dummy result for the debug_backtrace function
+        *
+        * @var array
+        */
+       protected $dummyBacktrace = array(
+               array(
+                       'file' => '/foo/filename1.php',
+                       'line' => 1,
+                       'class' => 'class1',
+                       'function' => 'function1'
+               ),
+               array(
+                       'file' => '/foo/filename2.php',
+                       'line' => 2,
+                       'class' => 'class2',
+                       'function' => 'function2'
+               ),
+               array(
+                       'class' => 'class3',
+                       'function' => 'function3'
+               ),
+               array(
+                       'file' => '/foo/filename4.php',
+                       'line' => 4,
+                       'class' => 'class4',
+                       'function' => 'function4'
+               )
+       );
+
+       /**
+        * Sets up this testcase
+        */
+       public function setUp() {
+               $this->processor = $this->getAccessibleMock(
+                       '\TYPO3\CMS\Core\Log\Processor\IntrospectionProcessor',
+                       array('getDebugBacktrace', 'formatDebugBacktrace')
+               );
+       }
+
+       /**
+        * @test
+        */
+       public function introspectionProcessorAddsLastBacktraceItemToLogRecord() {
+               $this->processor->expects($this->any())->method('getDebugBacktrace')->will($this->returnValue($this->dummyBacktrace));
+               $logRecord = new \TYPO3\CMS\Core\Log\LogRecord('test.core.log', \TYPO3\CMS\Core\Log\LogLevel::DEBUG, 'test');
+               $logRecord = $this->processor->processLogRecord($logRecord);
+
+               $this->assertEquals($this->dummyBacktrace[0]['file'], $logRecord['data']['file']);
+               $this->assertEquals($this->dummyBacktrace[0]['line'], $logRecord['data']['line']);
+               $this->assertEquals($this->dummyBacktrace[0]['class'], $logRecord['data']['class']);
+               $this->assertEquals($this->dummyBacktrace[0]['function'], $logRecord['data']['function']);
+       }
+
+       /**
+        * @test
+        */
+       public function introspectionProcessorShiftsLogRelatedFunctionsFromBacktrace() {
+               $dummyBacktrace = $this->dummyBacktrace;
+               array_unshift(
+                       $dummyBacktrace,
+                       array(
+                               'file' => '/foo/Log.php',
+                               'line' => 999,
+                               'class' => 'TYPO3\CMS\Core\Log\Bar\Foo',
+                               'function' => 'function999'
+                       ),
+                       array(
+                               'file' => '/foo/Log2.php',
+                               'line' => 888,
+                               'class' => 'TYPO3\CMS\Core\Log\Bar2\Foo2',
+                               'function' => 'function888'
+                       )
+               );
+               $this->processor->expects($this->any())->method('getDebugBacktrace')->will($this->returnValue($dummyBacktrace));
+
+               $logRecord = new \TYPO3\CMS\Core\Log\LogRecord('test.core.log', \TYPO3\CMS\Core\Log\LogLevel::DEBUG, 'test');
+               $logRecord = $this->processor->processLogRecord($logRecord);
+
+               $this->assertEquals($this->dummyBacktrace[0]['file'], $logRecord['data']['file']);
+               $this->assertEquals($this->dummyBacktrace[0]['line'], $logRecord['data']['line']);
+               $this->assertEquals($this->dummyBacktrace[0]['class'], $logRecord['data']['class']);
+               $this->assertEquals($this->dummyBacktrace[0]['function'], $logRecord['data']['function']);
+       }
+
+       /**
+        * DataProvider for introspectionProcessorShiftsGivenNumberOfEntriesFromBacktrace
+        */
+       public function introspectionProcessorShiftsGivenNumberOfEntriesFromBacktraceDataProvider() {
+               return array(
+                       array('0'),
+                       array('1'),
+                       array('3')
+               );
+       }
+
+       /**
+        * @test
+        * @dataProvider introspectionProcessorShiftsGivenNumberOfEntriesFromBacktraceDataProvider
+        */
+       public function introspectionProcessorShiftsGivenNumberOfEntriesFromBacktrace($number) {
+               $this->processor->expects($this->any())->method('getDebugBacktrace')->will($this->returnValue($this->dummyBacktrace));
+               $this->processor->setShiftBackTraceLevel($number);
+
+               $logRecord = new \TYPO3\CMS\Core\Log\LogRecord('test.core.log', \TYPO3\CMS\Core\Log\LogLevel::DEBUG, 'test');
+               $logRecord = $this->processor->processLogRecord($logRecord);
+
+               $this->assertEquals($this->dummyBacktrace[$number]['file'], $logRecord['data']['file']);
+               $this->assertEquals($this->dummyBacktrace[$number]['line'], $logRecord['data']['line']);
+               $this->assertEquals($this->dummyBacktrace[$number]['class'], $logRecord['data']['class']);
+               $this->assertEquals($this->dummyBacktrace[$number]['function'], $logRecord['data']['function']);
+       }
+
+       /**
+        * @test
+        */
+       public function introspectionProcessorLeavesOneEntryIfGivenNumberOfEntriesFromBacktraceIsGreaterOrEqualNumberOfBacktraceLevels() {
+               $this->processor->expects($this->any())->method('getDebugBacktrace')->will($this->returnValue($this->dummyBacktrace));
+               $this->processor->setShiftBackTraceLevel(4);
+
+               $logRecord = new \TYPO3\CMS\Core\Log\LogRecord('test.core.log', \TYPO3\CMS\Core\Log\LogLevel::DEBUG, 'test');
+               $logRecord = $this->processor->processLogRecord($logRecord);
+
+               $this->assertEquals($this->dummyBacktrace[3]['file'], $logRecord['data']['file']);
+               $this->assertEquals($this->dummyBacktrace[3]['line'], $logRecord['data']['line']);
+               $this->assertEquals($this->dummyBacktrace[3]['class'], $logRecord['data']['class']);
+               $this->assertEquals($this->dummyBacktrace[3]['function'], $logRecord['data']['function']);
+       }
+
+       /**
+        * @test
+        */
+       public function appendFullBacktraceAddsTheFullBacktraceAsStringToTheLog() {
+               $this->processor->expects($this->any())->method('getDebugBacktrace')->will($this->returnValue($this->dummyBacktrace));
+
+               $this->processor->setAppendFullBacktrace(TRUE);
+
+               $logRecord = new \TYPO3\CMS\Core\Log\LogRecord('test.core.log', \TYPO3\CMS\Core\Log\LogLevel::DEBUG, 'test');
+               $logRecord = $this->processor->processLogRecord($logRecord);
+
+               $this->assertContains($this->dummyBacktrace[0], $logRecord['data']['backtrace']);
+               $this->assertContains($this->dummyBacktrace[1], $logRecord['data']['backtrace']);
+               $this->assertContains($this->dummyBacktrace[2], $logRecord['data']['backtrace']);
+               $this->assertContains($this->dummyBacktrace[3], $logRecord['data']['backtrace']);
+       }
+}
\ No newline at end of file
diff --git a/typo3/sysext/core/Tests/Unit/Log/Processor/IntrospectionTest.php b/typo3/sysext/core/Tests/Unit/Log/Processor/IntrospectionTest.php
deleted file mode 100644 (file)
index ab963c0..0000000
+++ /dev/null
@@ -1,41 +0,0 @@
-<?php
-namespace TYPO3\CMS\Core\Tests\Unit\Log\Processor;
-
-/**
- * This file is part of the TYPO3 CMS project.
- *
- * It is free software; you can redistribute it and/or modify it under
- * the terms of the GNU General Public License, either version 2
- * of the License, or any later version.
- *
- * For the full copyright and license information, please read the
- * LICENSE.txt file that was distributed with this source code.
- *
- * The TYPO3 project - inspiring people to share!
- */
-
-/**
- * Testcase for the web introspection processor.
- *
- * @author Steffen Müller <typo3@t3node.com>
- */
-class IntrospectionTest extends \TYPO3\CMS\Core\Tests\UnitTestCase {
-
-       /**
-        * Tests if debug_backtrace values are added to LogRecord
-        * The debug_backtrace in \TYPO3\CMS\Core\Log\Processor\IntrospectionProcessor will always process a phpunit class.
-        * The result is unpredictable values. So we only test if values are not empty/0
-        *
-        * @test
-        */
-       public function introspectionProcessorAddsIntrospectionDataToLogRecord() {
-               $logRecord = new \TYPO3\CMS\Core\Log\LogRecord('test.core.log', \TYPO3\CMS\Core\Log\LogLevel::DEBUG, 'test');
-               $processor = new \TYPO3\CMS\Core\Log\Processor\IntrospectionProcessor();
-               $logRecord = $processor->processLogRecord($logRecord);
-               $this->assertNotEmpty($logRecord['data']['file'], 'Asserting that file name in debug_backtrace() is not empty');
-               $this->assertGreaterThan(0, $logRecord['data']['line'], 'Asserting that line numer in debug_backtrace() is greater than 0');
-               $this->assertNotEmpty($logRecord['data']['class'], 'Asserting that class in debug_backtrace() is not empty');
-               $this->assertNotEmpty($logRecord['data']['function'], 'Asserting that function in debug_backtrace() is not empty');
-       }
-
-}