diff --git a/composer.json b/composer.json index c3d5d45705..78abd98e73 100644 --- a/composer.json +++ b/composer.json @@ -34,8 +34,10 @@ "lightopenid/lightopenid": "dev-master", "michelf/php-markdown": "^1.7", "mobiledetect/mobiledetectlib": "2.8.*", + "monolog/monolog": "^1.24", "paragonie/random_compat": "^2.0", "pear/text_languageDetect": "1.*", + "psr/container": "^1.0", "seld/cli-prompt": "^1.0", "smarty/smarty": "^3.1", "fxp/composer-asset-plugin": "~1.3", @@ -49,9 +51,7 @@ "npm-asset/jgrowl": "^1.4", "npm-asset/fullcalendar": "^3.0.1", "npm-asset/cropperjs": "1.2.2", - "npm-asset/imagesloaded": "4.1.4", - "monolog/monolog": "^1.24", - "psr/container": "^1.0" + "npm-asset/imagesloaded": "4.1.4" }, "repositories": [ { diff --git a/src/Core/Logger.php b/src/Core/Logger.php index 0712c91b1c..d2b9e21eef 100644 --- a/src/Core/Logger.php +++ b/src/Core/Logger.php @@ -354,7 +354,7 @@ class Logger extends BaseObject } $stamp1 = microtime(true); - self::$devLogger->log($level, $msg); + self::$devLogger->log($level, $msg); self::getApp()->getProfiler()->saveTimestamp($stamp1, "file", System::callstack()); } } diff --git a/src/Util/Profiler.php b/src/Util/Profiler.php index e2d070075d..5bad5eb6ae 100644 --- a/src/Util/Profiler.php +++ b/src/Util/Profiler.php @@ -91,32 +91,49 @@ class Profiler implements ContainerInterface public function reset($performance = true, $callstack = true) { if ($performance) { - $this->performance = []; - $this->performance['start'] = microtime(true); - $this->performance['database'] = 0; - $this->performance['database_write'] = 0; - $this->performance['cache'] = 0; - $this->performance['cache_write'] = 0; - $this->performance['network'] = 0; - $this->performance['file'] = 0; - $this->performance['rendering'] = 0; - $this->performance['parser'] = 0; - $this->performance['marktime'] = 0; - $this->performance['marktime'] = microtime(true); + $this->resetPerformance(); } if ($callstack) { - $this->callstack['database'] = []; - $this->callstack['database_write'] = []; - $this->callstack['cache'] = []; - $this->callstack['cache_write'] = []; - $this->callstack['network'] = []; - $this->callstack['file'] = []; - $this->callstack['rendering'] = []; - $this->callstack['parser'] = []; + $this->resetCallstack(); } } + /** + * Resets the performance profiling data + */ + public function resetPerformance() + { + $this->performance = []; + $this->performance['start'] = microtime(true); + $this->performance['database'] = 0; + $this->performance['database_write'] = 0; + $this->performance['cache'] = 0; + $this->performance['cache_write'] = 0; + $this->performance['network'] = 0; + $this->performance['file'] = 0; + $this->performance['rendering'] = 0; + $this->performance['parser'] = 0; + $this->performance['marktime'] = 0; + $this->performance['marktime'] = microtime(true); + } + + /** + * Resets the callstack profiling data + */ + public function resetCallstack() + { + $this->callstack = []; + $this->callstack['database'] = []; + $this->callstack['database_write'] = []; + $this->callstack['cache'] = []; + $this->callstack['cache_write'] = []; + $this->callstack['network'] = []; + $this->callstack['file'] = []; + $this->callstack['rendering'] = []; + $this->callstack['parser'] = []; + } + /** * Save the current profiling data to a log entry * @@ -125,77 +142,79 @@ class Profiler implements ContainerInterface public function saveLog($message = '') { // Write down the performance values into the log - if ($this->enabled) { - $duration = microtime(true)-$this->get('start'); - $this->logger->info( - $message, - [ - 'module' => 'api', - 'action' => 'call', - 'database_read' => round($this->get('database') - $this->get('database_write'), 3), - 'database_write' => round($this->get('database_write'), 3), - 'cache_read' => round($this->get('cache'), 3), - 'cache_write' => round($this->get('cache_write'), 3), - 'network_io' => round($this->get('network'), 2), - 'file_io' => round($this->get('file'), 2), - 'other_io' => round($duration - ($this->get('database') - + $this->get('cache') + $this->get('cache_write') - + $this->get('network') + $this->get('file')), 2), - 'total' => round($duration, 2) - ] - ); - - $o = ''; - if ($this->rendertime) { - if (isset($this->callstack["database"])) { - $o .= "\nDatabase Read:\n"; - foreach ($this->callstack["database"] as $func => $time) { - $time = round($time, 3); - if ($time > 0) { - $o .= $func.": ".$time."\n"; - } - } - } - if (isset($this->callstack["database_write"])) { - $o .= "\nDatabase Write:\n"; - foreach ($this->callstack["database_write"] as $func => $time) { - $time = round($time, 3); - if ($time > 0) { - $o .= $func.": ".$time."\n"; - } - } - } - if (isset($this->callstack["cache"])) { - $o .= "\nCache Read:\n"; - foreach ($this->callstack["cache"] as $func => $time) { - $time = round($time, 3); - if ($time > 0) { - $o .= $func.": ".$time."\n"; - } - } - } - if (isset($this->callstack["cache_write"])) { - $o .= "\nCache Write:\n"; - foreach ($this->callstack["cache_write"] as $func => $time) { - $time = round($time, 3); - if ($time > 0) { - $o .= $func.": ".$time."\n"; - } - } - } - if (isset($this->callstack["network"])) { - $o .= "\nNetwork:\n"; - foreach ($this->callstack["network"] as $func => $time) { - $time = round($time, 3); - if ($time > 0) { - $o .= $func.": ".$time."\n"; - } - } - } - $this->logger->info($message . ": " . $o); - } - + if (!$this->enabled) { + return; } + $duration = microtime(true) - $this->get('start'); + $this->logger->info( + $message, + [ + 'module' => 'api', + 'action' => 'call', + 'database_read' => round($this->get('database') - $this->get('database_write'), 3), + 'database_write' => round($this->get('database_write'), 3), + 'cache_read' => round($this->get('cache'), 3), + 'cache_write' => round($this->get('cache_write'), 3), + 'network_io' => round($this->get('network'), 2), + 'file_io' => round($this->get('file'), 2), + 'other_io' => round($duration - ($this->get('database') + + $this->get('cache') + $this->get('cache_write') + + $this->get('network') + $this->get('file')), 2), + 'total' => round($duration, 2) + ] + ); + + if (!$this->rendertime) { + return; + } + + $o = ''; + if (isset($this->callstack["database"])) { + $o .= "\nDatabase Read:\n"; + foreach ($this->callstack["database"] as $func => $time) { + $time = round($time, 3); + if ($time > 0) { + $o .= $func . ": " . $time . "\n"; + } + } + } + if (isset($this->callstack["database_write"])) { + $o .= "\nDatabase Write:\n"; + foreach ($this->callstack["database_write"] as $func => $time) { + $time = round($time, 3); + if ($time > 0) { + $o .= $func . ": " . $time . "\n"; + } + } + } + if (isset($this->callstack["cache"])) { + $o .= "\nCache Read:\n"; + foreach ($this->callstack["cache"] as $func => $time) { + $time = round($time, 3); + if ($time > 0) { + $o .= $func . ": " . $time . "\n"; + } + } + } + if (isset($this->callstack["cache_write"])) { + $o .= "\nCache Write:\n"; + foreach ($this->callstack["cache_write"] as $func => $time) { + $time = round($time, 3); + if ($time > 0) { + $o .= $func . ": " . $time . "\n"; + } + } + } + if (isset($this->callstack["network"])) { + $o .= "\nNetwork:\n"; + foreach ($this->callstack["network"] as $func => $time) { + $time = round($time, 3); + if ($time > 0) { + $o .= $func . ": " . $time . "\n"; + } + } + } + $this->logger->info($message . ": " . $o); } /** diff --git a/tests/src/Core/Console/ConsoleTest.php b/tests/src/Core/Console/ConsoleTest.php index 905d214cac..715e68ab26 100644 --- a/tests/src/Core/Console/ConsoleTest.php +++ b/tests/src/Core/Console/ConsoleTest.php @@ -3,10 +3,12 @@ namespace Friendica\Test\src\Core\Console; use Asika\SimpleConsole\Console; +use Friendica\Core\Config\ConfigCache; use Friendica\Test\MockedTest; use Friendica\Test\Util\AppMockTrait; use Friendica\Test\Util\Intercept; use Friendica\Test\Util\VFSTrait; +use Friendica\Util\Profiler; abstract class ConsoleTest extends MockedTest { @@ -29,8 +31,10 @@ abstract class ConsoleTest extends MockedTest Intercept::setUp(); $this->setUpVfsDir(); - $configMock = \Mockery::mock('Friendica\Core\Config\ConfigCache'); + $configMock = \Mockery::mock(ConfigCache::class); $this->mockApp($this->root, $configMock); + $profileMock = \Mockery::mock(Profiler::class); + $this->app->shouldReceive('getProfiler')->andReturn($profileMock); } /**