Introducing Profiler

diff --git a/bin/auth_ejabberd.php b/bin/auth_ejabberd.php
index 11df438952a06e96ee700a7d6345cba1c90007d8..8a5c43c6dfb0ec274f251d415844679f800e47c6 100755 (executable)
--- a/bin/auth_ejabberd.php
+++ b/bin/auth_ejabberd.php
@@ -58,8 +58,9 @@ $basedir = BasePath::create(dirname(__DIR__), $_SERVER);
 $configLoader = new Config\ConfigCacheLoader($basedir);
 $config = Factory\ConfigFactory::createCache($configLoader);
 $logger = Factory\LoggerFactory::create('auth_ejabberd', $config);
+$profiler = Factory\ProfilerFactory::create($config);
 
-$a = new App($config, $logger);
+$a = new App($config, $logger, $profiler);
 
 if ($a->getMode()->isNormal()) {
        $oAuth = new ExAuth();

diff --git a/bin/console.php b/bin/console.php
index 9061824d875b0be10f8f1fad8aa94c1f883c55a0..ceccfc823edc08a0bc324e295da17d34a2459f9e 100755 (executable)
--- a/bin/console.php
+++ b/bin/console.php
@@ -11,8 +11,9 @@ $basedir = BasePath::create(dirname(__DIR__), $_SERVER);
 $configLoader = new Config\ConfigCacheLoader($basedir);
 $config = Factory\ConfigFactory::createCache($configLoader);
 $logger = Factory\LoggerFactory::create('console', $config);
+$profiler = Factory\ProfilerFactory::create($config);
 
-$a = new Friendica\App($config, $logger);
+$a = new Friendica\App($config, $logger, $profiler);
 \Friendica\BaseObject::setApp($a);
 
 (new Friendica\Core\Console($argv))->execute();

diff --git a/bin/daemon.php b/bin/daemon.php
index 5c014a92702429d58af4dfab1ac163597d34b95d..3b5c04b7abe645719a26ec22b0e0a4a96cfb7968 100755 (executable)
--- a/bin/daemon.php
+++ b/bin/daemon.php
@@ -37,8 +37,9 @@ $basedir = BasePath::create(dirname(__DIR__), $_SERVER);
 $configLoader = new Config\ConfigCacheLoader($basedir);
 $config = Factory\ConfigFactory::createCache($configLoader);
 $logger = Factory\LoggerFactory::create('daemon', $config);
+$profiler = Factory\ProfilerFactory::create($config);
 
-$a = new App($config, $logger);
+$a = new App($config, $logger, $profiler);
 
 if ($a->getMode()->isInstall()) {
        die("Friendica isn't properly installed yet.\n");

diff --git a/bin/worker.php b/bin/worker.php
index 553e9849774fe307e5f1535b9c090809ce043e80..c93abaf0fedc2a454c2fc46006e30ace4434b2d8 100755 (executable)
--- a/bin/worker.php
+++ b/bin/worker.php
@@ -35,8 +35,9 @@ $basedir = BasePath::create(dirname(__DIR__), $_SERVER);
 $configLoader = new Config\ConfigCacheLoader($basedir);
 $config = Factory\ConfigFactory::createCache($configLoader);
 $logger = Factory\LoggerFactory::create('worker', $config);
+$profiler = Factory\ProfilerFactory::create($config);
 
-$a = new App($config, $logger);
+$a = new App($config, $logger, $profiler);
 
 // Check the database structure and possibly fixes it
 Update::check($a->getBasePath(), true);

diff --git a/include/api.php b/include/api.php
index 052d32b17b1f8d788db0d7c65559febeb6cd3aa1..6bd08d01d0cb6bc43e246216098eacefd7aeb598 100644 (file)
--- a/include/api.php
+++ b/include/api.php
@@ -326,69 +326,7 @@ function api_call(App $a)
 
                                Logger::info(API_LOG_PREFIX . 'username {username}', ['module' => 'api', 'action' => 'call', 'username' => $a->user['username'], 'duration' => round($duration, 2)]);
 
-                               if (Config::get("system", "profiler")) {
-                                       $duration = microtime(true)-$a->performance["start"];
-
-                                       /// @TODO round() really everywhere?
-                                       Logger::debug(
-                                               API_LOG_PREFIX . 'performance',
-                                               [
-                                                       'module' => 'api',
-                                                       'action' => 'call',
-                                                       'database_read' => round($a->performance["database"] - $a->performance["database_write"], 3),
-                                                       'database_write' => round($a->performance["database_write"], 3),
-                                                       'cache_read' => round($a->performance["cache"], 3),
-                                                       'cache_write' => round($a->performance["cache_write"], 3),
-                                                       'network_io' => round($a->performance["network"], 2),
-                                                       'file_io' => round($a->performance["file"], 2),
-                                                       'other_io' => round($duration - ($a->performance["database"]
-                                                                       + $a->performance["cache"] + $a->performance["cache_write"]
-                                                                       + $a->performance["network"] + $a->performance["file"]), 2),
-                                                       'total' => round($duration, 2)
-                                               ]
-                                       );
-
-                                       if (Config::get("rendertime", "callstack")) {
-                                               $o = "Database Read:\n";
-                                               foreach ($a->callstack["database"] as $func => $time) {
-                                                       $time = round($time, 3);
-                                                       if ($time > 0) {
-                                                               $o .= $func . ": " . $time . "\n";
-                                                       }
-                                               }
-                                               $o .= "\nDatabase Write:\n";
-                                               foreach ($a->callstack["database_write"] as $func => $time) {
-                                                       $time = round($time, 3);
-                                                       if ($time > 0) {
-                                                               $o .= $func . ": " . $time . "\n";
-                                                       }
-                                               }
-
-                                               $o = "Cache Read:\n";
-                                               foreach ($a->callstack["cache"] as $func => $time) {
-                                                       $time = round($time, 3);
-                                                       if ($time > 0) {
-                                                               $o .= $func . ": " . $time . "\n";
-                                                       }
-                                               }
-                                               $o .= "\nCache Write:\n";
-                                               foreach ($a->callstack["cache_write"] as $func => $time) {
-                                                       $time = round($time, 3);
-                                                       if ($time > 0) {
-                                                               $o .= $func . ": " . $time . "\n";
-                                                       }
-                                               }
-
-                                               $o .= "\nNetwork:\n";
-                                               foreach ($a->callstack["network"] as $func => $time) {
-                                                       $time = round($time, 3);
-                                                       if ($time > 0) {
-                                                               $o .= $func . ": " . $time . "\n";
-                                                       }
-                                               }
-                                               Logger::debug(API_LOG_PREFIX . $o, ['module' => 'api', 'action' => 'call']);
-                                       }
-                               }
+                               $a->getProfiler()->saveLog(API_LOG_PREFIX . 'performance');
 
                                if (false === $return) {
                                        /*

diff --git a/index.php b/index.php
index 7e7396785f5993c7b17f7a1e74870b7be5b4afcd..d8c233be23a1ef2e09d639d49ec9c10cb6cb4cab 100644 (file)
--- a/index.php
+++ b/index.php
@@ -19,9 +19,10 @@ $basedir = BasePath::create(__DIR__, $_SERVER);
 $configLoader = new Config\ConfigCacheLoader($basedir);
 $config = Factory\ConfigFactory::createCache($configLoader);
 $logger = Factory\LoggerFactory::create('index', $config);
+$profiler = Factory\ProfilerFactory::create($config);
 
 // We assume that the index.php is called by a frontend process
 // The value is set to "true" by default in App
-$a = new App($config, $logger, false);
+$a = new App($config, $logger, $profiler, false);
 
 $a->runFrontend();

diff --git a/src/App.php b/src/App.php
index 8068a1530bad71a2e3c462e48c710f2751d99b68..6e1f83fdd6bd5c9836e2ca4dcee69d40dd9ac90d 100644 (file)
--- a/src/App.php
+++ b/src/App.php
@@ -13,6 +13,7 @@ use Friendica\Core\Config\ConfigCacheLoader;
 use Friendica\Database\DBA;
 use Friendica\Factory\ConfigFactory;
 use Friendica\Network\HTTPException\InternalServerErrorException;
+use Friendica\Util\Profiler;
 use Psr\Log\LoggerInterface;
 
 /**
@@ -53,8 +54,6 @@ class App
        public $identities;
        public $is_mobile = false;
        public $is_tablet = false;
-       public $performance = [];
-       public $callstack = [];
        public $theme_info = [];
        public $category;
        // Allow themes to control internal parameters
@@ -119,6 +118,11 @@ class App
         */
        private $config;
 
+       /**
+        * @var Profiler The profiler of this app
+        */
+       private $profiler;
+
        /**
         * Returns the current config cache of this node
         *
@@ -139,6 +143,16 @@ class App
                return $this->basePath;
        }
 
+       /**
+        * The profiler of this app
+        *
+        * @return Profiler
+        */
+       public function getProfiler()
+       {
+               return $this->profiler;
+       }
+
        /**
         * Register a stylesheet file path to be included in the <head> tag of every page.
         * Inclusion is done in App->initHead().
@@ -183,14 +197,16 @@ class App
         *
         * @param ConfigCache      $config    The Cached Config
         * @param LoggerInterface  $logger    Logger of this application
+        * @param Profiler         $profiler  The profiler of this application
         * @param bool             $isBackend Whether it is used for backend or frontend (Default true=backend)
         *
         * @throws Exception if the Basepath is not usable
         */
-       public function __construct(ConfigCache $config, LoggerInterface $logger, $isBackend = true)
+       public function __construct(ConfigCache $config, LoggerInterface $logger, Profiler $profiler, $isBackend = true)
        {
                $this->config   = $config;
                $this->logger   = $logger;
+               $this->profiler = $profiler;
                $this->basePath = $this->config->get('system', 'basepath');
 
                if (!Core\System::isDirectoryUsable($this->basePath, false)) {
@@ -203,26 +219,7 @@ class App
                $this->checkBackend($isBackend);
                $this->checkFriendicaApp();
 
-               $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['markstart'] = microtime(true);
-
-               $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->profiler->reset();
 
                $this->mode = new App\Mode($this->basePath);
 
@@ -489,14 +486,14 @@ class App
 
                $stamp1 = microtime(true);
 
-               if (DBA::connect($this->config, $db_host, $db_user, $db_pass, $db_data, $charset)) {
+               if (DBA::connect($this->config, $this->profiler, $db_host, $db_user, $db_pass, $db_data, $charset)) {
                        // Loads DB_UPDATE_VERSION constant
                        Database\DBStructure::definition($this->basePath, false);
                }
 
                unset($db_host, $db_user, $db_pass, $db_data, $charset);
 
-               $this->saveTimestamp($stamp1, 'network');
+               $this->profiler->saveTimestamp($stamp1, 'network');
        }
 
        public function getScheme()
@@ -742,41 +739,6 @@ class App
                }
        }
 
-       /**
-        * Saves a timestamp for a value - f.e. a call
-        * Necessary for profiling Friendica
-        *
-        * @param int $timestamp the Timestamp
-        * @param string $value A value to profile
-        */
-       public function saveTimestamp($timestamp, $value)
-       {
-               $profiler = $this->config->get('system', 'profiler');
-
-               if (!isset($profiler) || !$profiler) {
-                       return;
-               }
-
-               $duration = (float) (microtime(true) - $timestamp);
-
-               if (!isset($this->performance[$value])) {
-                       // Prevent ugly E_NOTICE
-                       $this->performance[$value] = 0;
-               }
-
-               $this->performance[$value] += (float) $duration;
-               $this->performance['marktime'] += (float) $duration;
-
-               $callstack = Core\System::callstack();
-
-               if (!isset($this->callstack[$value][$callstack])) {
-                       // Prevent ugly E_NOTICE
-                       $this->callstack[$value][$callstack] = 0;
-               }
-
-               $this->callstack[$value][$callstack] += (float) $duration;
-       }
-
        /**
         * Returns the current UserAgent as a String
         *
@@ -1227,7 +1189,7 @@ class App
                if (!$this->isBackend()) {
                        $stamp1 = microtime(true);
                        session_start();
-                       $this->saveTimestamp($stamp1, 'parser');
+                       $this->profiler->saveTimestamp($stamp1, 'parser');
                        Core\L10n::setSessionVariable();
                        Core\L10n::setLangFromSession();
                } else {

diff --git a/src/Content/Text/BBCode.php b/src/Content/Text/BBCode.php
index a8b5ec2025546e7ffa0e694597d2f38524ccd8b1..75cb32b626950c9e7b4f8ea49973ff466f28d61f 100644 (file)
--- a/src/Content/Text/BBCode.php
+++ b/src/Content/Text/BBCode.php
@@ -1027,7 +1027,7 @@ class BBCode extends BaseObject
                        @curl_exec($ch);
                        $curl_info = @curl_getinfo($ch);
 
-                       $a->saveTimestamp($stamp1, "network");
+                       $a->getProfiler()->saveTimestamp($stamp1, "network");
 
                        if (substr($curl_info["content_type"], 0, 6) == "image/") {
                                $text = "[url=" . $match[1] . "]" . $match[1] . "[/url]";
@@ -1086,7 +1086,7 @@ class BBCode extends BaseObject
                        @curl_exec($ch);
                        $curl_info = @curl_getinfo($ch);
 
-                       $a->saveTimestamp($stamp1, "network");
+                       $a->getProfiler()->saveTimestamp($stamp1, "network");
 
                        // if its a link to a picture then embed this picture
                        if (substr($curl_info["content_type"], 0, 6) == "image/") {
@@ -1915,7 +1915,7 @@ class BBCode extends BaseObject
                // unmask the special chars back to HTML
                $text = str_replace(['&\_lt\_;', '&\_gt\_;', '&\_amp\_;'], ['<', '>', '&'], $text);
 
-               $a->saveTimestamp($stamp1, "parser");
+               $a->getProfiler()->saveTimestamp($stamp1, "parser");
 
                // Libertree has a problem with escaped hashtags.
                $text = str_replace(['\#'], ['#'], $text);

diff --git a/src/Content/Text/Markdown.php b/src/Content/Text/Markdown.php
index ceb5b043b3065ba045c27891fc0138df916afd31..28ee215b2674aa3810e31b73f245f8ef3bd00694 100644 (file)
--- a/src/Content/Text/Markdown.php
+++ b/src/Content/Text/Markdown.php
@@ -36,7 +36,7 @@ class Markdown extends BaseObject
                $html = $MarkdownParser->transform($text);
                $html = preg_replace('/<a(.*?)href="#/is', '<a$1href="' . ltrim($_SERVER['REQUEST_URI'], '/') . '#', $html);
 
-               self::getApp()->saveTimestamp($stamp1, "parser");
+               self::getApp()->getProfiler()->saveTimestamp($stamp1, "parser");
 
                return $html;
        }

diff --git a/src/Core/Addon.php b/src/Core/Addon.php
index 6697a44aea13bd60b480fa0cb067d4fa5e9f2be5..483882c3edc3036134ff8073fa094e4776b31590 100644 (file)
--- a/src/Core/Addon.php
+++ b/src/Core/Addon.php
@@ -219,7 +219,7 @@ class Addon extends BaseObject
 
                $stamp1 = microtime(true);
                $f = file_get_contents("addon/$addon/$addon.php");
-               $a->saveTimestamp($stamp1, "file");
+               $a->getProfiler()->saveTimestamp($stamp1, "file");
 
                $r = preg_match("|/\*.*\*/|msU", $f, $m);
 

diff --git a/src/Core/Cache.php b/src/Core/Cache.php
index 39c29566d3560df5c5d0ede30804c42ce10798d0..cd1581ef930a326418777509fe6162cd7a6c8a2b 100644 (file)
--- a/src/Core/Cache.php
+++ b/src/Core/Cache.php
@@ -63,7 +63,7 @@ class Cache extends \Friendica\BaseObject
 
                $return = self::getDriver()->getAllKeys($prefix);
 
-               self::getApp()->saveTimestamp($time, 'cache');
+               self::getApp()->getProfiler()->saveTimestamp($time, 'cache');
 
                return $return;
        }
@@ -82,7 +82,7 @@ class Cache extends \Friendica\BaseObject
 
                $return = self::getDriver()->get($key);
 
-               self::getApp()->saveTimestamp($time, 'cache');
+               self::getApp()->getProfiler()->saveTimestamp($time, 'cache');
 
                return $return;
        }
@@ -105,7 +105,7 @@ class Cache extends \Friendica\BaseObject
 
                $return = self::getDriver()->set($key, $value, $duration);
 
-               self::getApp()->saveTimestamp($time, 'cache_write');
+               self::getApp()->getProfiler()->saveTimestamp($time, 'cache_write');
 
                return $return;
        }
@@ -124,7 +124,7 @@ class Cache extends \Friendica\BaseObject
 
                $return = self::getDriver()->delete($key);
 
-               self::getApp()->saveTimestamp($time, 'cache_write');
+               self::getApp()->getProfiler()->saveTimestamp($time, 'cache_write');
 
                return $return;
        }

diff --git a/src/Core/Console/AutomaticInstallation.php b/src/Core/Console/AutomaticInstallation.php
index 7f2585e63a3f359bfee056fbfa2f79a40bd59f21..d5c63dd990e17cd115b634fc4e6f934be55b0af5 100644 (file)
--- a/src/Core/Console/AutomaticInstallation.php
+++ b/src/Core/Console/AutomaticInstallation.php
@@ -146,7 +146,7 @@ HELP;
 
                $installer->resetChecks();
 
-               if (!$installer->checkDB($a->getConfig(), $db_host, $db_user, $db_pass, $db_data)) {
+               if (!$installer->checkDB($a->getConfig(), $a->getProfiler(), $db_host, $db_user, $db_pass, $db_data)) {
                        $errorMessage = $this->extractErrors($installer->getChecks());
                        throw new RuntimeException($errorMessage);
                }

diff --git a/src/Core/Installer.php b/src/Core/Installer.php
index 4a287a885f50e9d5e47988de099608fe567f4e74..dd9e3d22e94238cc575f1a3dee778b2a97aae8d4 100644 (file)
--- a/src/Core/Installer.php
+++ b/src/Core/Installer.php
@@ -11,6 +11,7 @@ use Friendica\Database\DBA;
 use Friendica\Database\DBStructure;
 use Friendica\Object\Image;
 use Friendica\Util\Network;
+use Friendica\Util\Profiler;
 use Friendica\Util\Strings;
 
 /**
@@ -583,6 +584,7 @@ class Installer
         * Checking the Database connection and if it is available for the current installation
         *
         * @param ConfigCache $configCache The configuration cache
+        * @param Profiler    $profiler    The profiler of this app
         * @param string $dbhost           Hostname/IP of the Friendica Database
         * @param string $dbuser           Username of the Database connection credentials
         * @param string $dbpass           Password of the Database connection credentials
@@ -591,9 +593,9 @@ class Installer
         * @return bool true if the check was successful, otherwise false
         * @throws Exception
         */
-       public function checkDB(ConfigCache $configCache, $dbhost, $dbuser, $dbpass, $dbdata)
+       public function checkDB(ConfigCache $configCache, Profiler $profiler, $dbhost, $dbuser, $dbpass, $dbdata)
        {
-               if (!DBA::connect($configCache, $dbhost, $dbuser, $dbpass, $dbdata)) {
+               if (!DBA::connect($configCache, $profiler, $dbhost, $dbuser, $dbpass, $dbdata)) {
                        $this->addCheck(L10n::t('Could not connect to database.'), false, true, '');
 
                        return false;

diff --git a/src/Core/Logger.php b/src/Core/Logger.php
index 6b8112796f557f00dea156a9c22fef3993097584..69be501a3d3efa59af37a10f53874b73a4763726 100644 (file)
--- a/src/Core/Logger.php
+++ b/src/Core/Logger.php
@@ -155,7 +155,7 @@ class Logger extends BaseObject
 
                $stamp1 = microtime(true);
                self::$logger->emergency($message, $context);
-               self::getApp()->saveTimestamp($stamp1, 'file');
+               self::getApp()->GetProfiler()->saveTimestamp($stamp1, 'file');
        }
 
        /**
@@ -179,7 +179,7 @@ class Logger extends BaseObject
 
                $stamp1 = microtime(true);
                self::$logger->alert($message, $context);
-               self::getApp()->saveTimestamp($stamp1, 'file');
+               self::getApp()->getProfiler()->saveTimestamp($stamp1, 'file');
        }
 
        /**
@@ -202,7 +202,7 @@ class Logger extends BaseObject
 
                $stamp1 = microtime(true);
                self::$logger->critical($message, $context);
-               self::getApp()->saveTimestamp($stamp1, 'file');
+               self::getApp()->getProfiler()->saveTimestamp($stamp1, 'file');
        }
 
        /**
@@ -225,7 +225,7 @@ class Logger extends BaseObject
 
                $stamp1 = microtime(true);
                self::$logger->error($message, $context);
-               self::getApp()->saveTimestamp($stamp1, 'file');
+               self::getApp()->getProfiler()->saveTimestamp($stamp1, 'file');
        }
 
        /**
@@ -249,7 +249,7 @@ class Logger extends BaseObject
 
                $stamp1 = microtime(true);
                self::$logger->warning($message, $context);
-               self::getApp()->saveTimestamp($stamp1, 'file');
+               self::getApp()->getProfiler()->saveTimestamp($stamp1, 'file');
        }
 
        /**
@@ -270,7 +270,7 @@ class Logger extends BaseObject
 
                $stamp1 = microtime(true);
                self::$logger->notice($message, $context);
-               self::getApp()->saveTimestamp($stamp1, 'file');
+               self::getApp()->getProfiler()->saveTimestamp($stamp1, 'file');
        }
 
        /**
@@ -293,7 +293,7 @@ class Logger extends BaseObject
 
                $stamp1 = microtime(true);
                self::$logger->info($message, $context);
-               self::getApp()->saveTimestamp($stamp1, 'file');
+               self::getApp()->getProfiler()->saveTimestamp($stamp1, 'file');
        }
 
        /**
@@ -314,7 +314,7 @@ class Logger extends BaseObject
 
                $stamp1 = microtime(true);
                self::$logger->debug($message, $context);
-               self::getApp()->saveTimestamp($stamp1, 'file');
+               self::getApp()->getProfiler()->saveTimestamp($stamp1, 'file');
        }
 
     /**
@@ -334,7 +334,7 @@ class Logger extends BaseObject
 
         $stamp1 = microtime(true);
                self::$logger->log($level, $msg);
-        self::getApp()->saveTimestamp($stamp1, "file");
+               self::getApp()->getProfiler()->saveTimestamp($stamp1, "file");
     }
 
        /**
@@ -355,6 +355,6 @@ class Logger extends BaseObject
 
         $stamp1 = microtime(true);
         self::$devLogger->log($level, $msg);
-        self::getApp()->saveTimestamp($stamp1, "file");
+               self::getApp()->getProfiler()->saveTimestamp($stamp1, "file");
     }
 }

diff --git a/src/Core/Renderer.php b/src/Core/Renderer.php
index 67bc5e3babc515a6377d9b013a6e20d018d349b5..c032448c984b73f7f12113226e5521cac2ead9de 100644 (file)
--- a/src/Core/Renderer.php
+++ b/src/Core/Renderer.php
@@ -74,7 +74,7 @@ class Renderer extends BaseObject
             exit();
         }
 
-        $a->saveTimestamp($stamp1, "rendering");
+               $a->getProfiler()->saveTimestamp($stamp1, "rendering");
 
         return $output;
     }
@@ -101,7 +101,7 @@ class Renderer extends BaseObject
             exit();
         }
 
-        $a->saveTimestamp($stamp1, "file");
+        $a->getProfiler()->saveTimestamp($stamp1, "file");
 
         return $template;
     }

diff --git a/src/Core/Theme.php b/src/Core/Theme.php
index 62dfaa51f3072f45ce8d3bc56e871b2f0f4e3d5a..dbfc0fd908bcfbcf0e76bb17f1c6b5ec6a28a46b 100644 (file)
--- a/src/Core/Theme.php
+++ b/src/Core/Theme.php
@@ -51,7 +51,7 @@ class Theme
                $a = \get_app();
                $stamp1 = microtime(true);
                $theme_file = file_get_contents("view/theme/$theme/theme.php");
-               $a->saveTimestamp($stamp1, "file");
+               $a->getProfiler()->saveTimestamp($stamp1, "file");
 
                $result = preg_match("|/\*.*\*/|msU", $theme_file, $matches);
 

diff --git a/src/Core/Worker.php b/src/Core/Worker.php
index 75d4e48740ef60867b179a3da2ac12d97b5c5525..dff60e9fa5571187a09b913c2dedb7064669be6d 100644 (file)
--- a/src/Core/Worker.php
+++ b/src/Core/Worker.php
@@ -380,20 +380,7 @@ class Worker
 
                // We use the callstack here to analyze the performance of executed worker entries.
                // For this reason the variables have to be initialized.
-               if (Config::get("system", "profiler")) {
-                       $a->performance["start"] = microtime(true);
-                       $a->performance["database"] = 0;
-                       $a->performance["database_write"] = 0;
-                       $a->performance["cache"] = 0;
-                       $a->performance["cache_write"] = 0;
-                       $a->performance["network"] = 0;
-                       $a->performance["file"] = 0;
-                       $a->performance["rendering"] = 0;
-                       $a->performance["parser"] = 0;
-                       $a->performance["marktime"] = 0;
-                       $a->performance["markstart"] = microtime(true);
-                       $a->callstack = [];
-               }
+               $a->getProfiler()->reset();
 
                // For better logging create a new process id for every worker call
                // But preserve the old one for the worker
@@ -452,76 +439,7 @@ class Worker
 
                Logger::log("Process ".$mypid." - Prio ".$queue["priority"]." - ID ".$queue["id"].": ".$funcname." - done in ".number_format($duration, 4)." seconds. Process PID: ".$new_process_id);
 
-               // Write down the performance values into the log
-               if (Config::get("system", "profiler")) {
-                       $duration = microtime(true)-$a->performance["start"];
-
-                       $o = '';
-                       if (Config::get("rendertime", "callstack")) {
-                               if (isset($a->callstack["database"])) {
-                                       $o .= "\nDatabase Read:\n";
-                                       foreach ($a->callstack["database"] as $func => $time) {
-                                               $time = round($time, 3);
-                                               if ($time > 0) {
-                                                       $o .= $func.": ".$time."\n";
-                                               }
-                                       }
-                               }
-                               if (isset($a->callstack["database_write"])) {
-                                       $o .= "\nDatabase Write:\n";
-                                       foreach ($a->callstack["database_write"] as $func => $time) {
-                                               $time = round($time, 3);
-                                               if ($time > 0) {
-                                                       $o .= $func.": ".$time."\n";
-                                               }
-                                       }
-                               }
-                               if (isset($a->callstack["dache"])) {
-                                       $o .= "\nCache Read:\n";
-                                       foreach ($a->callstack["dache"] as $func => $time) {
-                                               $time = round($time, 3);
-                                               if ($time > 0) {
-                                                       $o .= $func.": ".$time."\n";
-                                               }
-                                       }
-                               }
-                               if (isset($a->callstack["dache_write"])) {
-                                       $o .= "\nCache Write:\n";
-                                       foreach ($a->callstack["dache_write"] as $func => $time) {
-                                               $time = round($time, 3);
-                                               if ($time > 0) {
-                                                       $o .= $func.": ".$time."\n";
-                                               }
-                                       }
-                               }
-                               if (isset($a->callstack["network"])) {
-                                       $o .= "\nNetwork:\n";
-                                       foreach ($a->callstack["network"] as $func => $time) {
-                                               $time = round($time, 3);
-                                               if ($time > 0) {
-                                                       $o .= $func.": ".$time."\n";
-                                               }
-                                       }
-                               }
-                       }
-
-                       Logger::log(
-                               "ID ".$queue["id"].": ".$funcname.": ".sprintf(
-                                       "DB: %s/%s, Cache: %s/%s, Net: %s, I/O: %s, Other: %s, Total: %s".$o,
-                                       number_format($a->performance["database"] - $a->performance["database_write"], 2),
-                                       number_format($a->performance["database_write"], 2),
-                                       number_format($a->performance["cache"], 2),
-                                       number_format($a->performance["cache_write"], 2),
-                                       number_format($a->performance["network"], 2),
-                                       number_format($a->performance["file"], 2),
-                                       number_format($duration - ($a->performance["database"]
-                                               + $a->performance["cache"] + $a->performance["cache_write"]
-                                               + $a->performance["network"] + $a->performance["file"]), 2),
-                                       number_format($duration, 2)
-                               ),
-                               Logger::DEBUG
-                       );
-               }
+               $a->getProfiler()->saveLog("ID " . $queue["id"] . ": " . $funcname);
 
                $cooldown = Config::get("system", "worker_cooldown", 0);
 

diff --git a/src/Database/DBA.php b/src/Database/DBA.php
index d2a739e9313aa07b9be4aaf948bab6398c1930e2..7c24ecfd336ae42b5297bef1afd37eb1aad7230e 100644 (file)
--- a/src/Database/DBA.php
+++ b/src/Database/DBA.php
@@ -6,6 +6,7 @@ use Friendica\Core\Config\IConfigCache;
 use Friendica\Core\Logger;
 use Friendica\Core\System;
 use Friendica\Util\DateTimeFormat;
+use Friendica\Util\Profiler;
 use mysqli;
 use mysqli_result;
 use mysqli_stmt;
@@ -35,6 +36,10 @@ class DBA
         * @var IConfigCache
         */
        private static $configCache;
+       /**
+        * @var Profiler
+        */
+       private static $profiler;
        private static $server_info = '';
        private static $connection;
        private static $driver;
@@ -50,7 +55,7 @@ class DBA
        private static $db_name = '';
        private static $db_charset = '';
 
-       public static function connect($configCache, $serveraddr, $user, $pass, $db, $charset = null)
+       public static function connect(IConfigCache $configCache, Profiler $profiler, $serveraddr, $user, $pass, $db, $charset = null)
        {
                if (!is_null(self::$connection) && self::connected()) {
                        return true;
@@ -58,6 +63,7 @@ class DBA
 
                // We are storing these values for being able to perform a reconnect
                self::$configCache = $configCache;
+               self::$profiler = $profiler;
                self::$db_serveraddr = $serveraddr;
                self::$db_user = $user;
                self::$db_pass = $pass;
@@ -158,7 +164,7 @@ class DBA
        public static function reconnect() {
                self::disconnect();
 
-               $ret = self::connect(self::$configCache, self::$db_serveraddr, self::$db_user, self::$db_pass, self::$db_name, self::$db_charset);
+               $ret = self::connect(self::$configCache, self::$profiler, self::$db_serveraddr, self::$db_user, self::$db_pass, self::$db_name, self::$db_charset);
                return $ret;
        }
 
@@ -392,7 +398,6 @@ class DBA
         * @throws \Exception
         */
        public static function p($sql) {
-               $a = \get_app();
 
                $stamp1 = microtime(true);
 
@@ -582,7 +587,7 @@ class DBA
                        self::$errorno = $errorno;
                }
 
-               $a->saveTimestamp($stamp1, 'database');
+               self::$profiler->saveTimestamp($stamp1, 'database');
 
                if (self::$configCache->get('system', 'db_log')) {
                        $stamp2 = microtime(true);
@@ -611,7 +616,6 @@ class DBA
         * @throws \Exception
         */
        public static function e($sql) {
-               $a = \get_app();
 
                $stamp = microtime(true);
 
@@ -654,7 +658,7 @@ class DBA
                        self::$errorno = $errorno;
                }
 
-               $a->saveTimestamp($stamp, "database_write");
+               self::$profiler->saveTimestamp($stamp, "database_write");
 
                return $retval;
        }
@@ -777,7 +781,6 @@ class DBA
         * @return array current row
         */
        public static function fetch($stmt) {
-               $a = \get_app();
 
                $stamp1 = microtime(true);
 
@@ -824,7 +827,7 @@ class DBA
                                }
                }
 
-               $a->saveTimestamp($stamp1, 'database');
+               self::$profiler->saveTimestamp($stamp1, 'database');
 
                return $columns;
        }
@@ -1534,7 +1537,6 @@ class DBA
         * @return boolean was the close successful?
         */
        public static function close($stmt) {
-               $a = \get_app();
 
                $stamp1 = microtime(true);
 
@@ -1562,7 +1564,7 @@ class DBA
                                break;
                }
 
-               $a->saveTimestamp($stamp1, 'database');
+               self::$profiler->saveTimestamp($stamp1, 'database');
 
                return $ret;
        }

diff --git a/src/Factory/ProfilerFactory.php b/src/Factory/ProfilerFactory.php
new file mode 100644 (file)
index 0000000..7a63c74
--- /dev/null
+++ b/src/Factory/ProfilerFactory.php
@@ -0,0 +1,25 @@
+<?php
+
+namespace Friendica\Factory;
+
+use Friendica\Core\Config\ConfigCache;
+use Friendica\Util\Profiler;
+use Psr\Log\LoggerInterface;
+
+class ProfilerFactory
+{
+       /**
+        * Creates a Profiler for the current execution
+        *
+        * @param LoggerInterface $logger      The logger for saving the profiling data
+        * @param ConfigCache     $configCache The configuration cache
+        *
+        * @return Profiler
+        */
+       public static function create(LoggerInterface $logger, ConfigCache $configCache)
+       {
+               $enabled = $configCache->get('system', 'profiler', false);
+               $renderTime = $configCache->get('rendertime', 'callstack', false);
+               return new Profiler($logger, $enabled, $renderTime);
+       }
+}

diff --git a/src/Module/Install.php b/src/Module/Install.php
index 6948dee6e0c52255c1f30d46c20c91b94a673769..4fb4a932cdc25570a08f2a6701058b01a2aa5135 100644 (file)
--- a/src/Module/Install.php
+++ b/src/Module/Install.php
@@ -75,7 +75,7 @@ class Install extends BaseModule
                                $dbdata  = Strings::escapeTags(trim(defaults($_POST, 'dbdata', '')));
 
                                // If we cannot connect to the database, return to the previous step
-                               if (!self::$installer->checkDB($a->getConfig(), $dbhost, $dbuser, $dbpass, $dbdata)) {
+                               if (!self::$installer->checkDB($a->getConfig(), $a->getProfiler(), $dbhost, $dbuser, $dbpass, $dbdata)) {
                                        self::$currentWizardStep = self::DATABASE_CONFIG;
                                }
 
@@ -92,7 +92,7 @@ class Install extends BaseModule
                                $adminmail = Strings::escapeTags(trim(defaults($_POST, 'adminmail', '')));
 
                                // If we cannot connect to the database, return to the Database config wizard
-                               if (!self::$installer->checkDB($a->getConfig(), $dbhost, $dbuser, $dbpass, $dbdata)) {
+                               if (!self::$installer->checkDB($a->getConfig(), $a->getProfiler(), $dbhost, $dbuser, $dbpass, $dbdata)) {
                                        self::$currentWizardStep = self::DATABASE_CONFIG;
                                        return;
                                }

diff --git a/src/Object/Image.php b/src/Object/Image.php
index 9143c23c16b3d2d15f095a097832df604365d6d1..c43955375402984a4249864a9c89de3709219bf7 100644 (file)
--- a/src/Object/Image.php
+++ b/src/Object/Image.php
@@ -5,6 +5,7 @@
  */
 namespace Friendica\Object;
 
+use Exception;
 use Friendica\App;
 use Friendica\Core\Cache;
 use Friendica\Core\Config;
@@ -14,7 +15,6 @@ use Friendica\Core\System;
 use Friendica\Database\DBA;
 use Friendica\Model\Photo;
 use Friendica\Util\Network;
-use Exception;
 use Imagick;
 use ImagickPixel;
 
@@ -656,7 +656,7 @@ class Image
 
                $stamp1 = microtime(true);
                file_put_contents($path, $string);
-               $a->saveTimestamp($stamp1, "file");
+               $a->getProfiler()->saveTimestamp($stamp1, "file");
        }
 
        /**
@@ -802,7 +802,7 @@ class Image
                                        $a = \get_app();
                                        $stamp1 = microtime(true);
                                        file_put_contents($tempfile, $img_str);
-                                       $a->saveTimestamp($stamp1, "file");
+                                       $a->getProfiler()->saveTimestamp($stamp1, "file");
 
                                        $data = getimagesize($tempfile);
                                        unlink($tempfile);
@@ -910,7 +910,7 @@ class Image
 
                        $stamp1 = microtime(true);
                        $imagedata = @file_get_contents($url);
-                       $a->saveTimestamp($stamp1, "file");
+                       $a->getProfiler()->saveTimestamp($stamp1, "file");
                }
 
                $maximagesize = Config::get('system', 'maximagesize');
@@ -924,7 +924,7 @@ class Image
 
                $stamp1 = microtime(true);
                file_put_contents($tempfile, $imagedata);
-               $a->saveTimestamp($stamp1, "file");
+               $a->getProfiler()->saveTimestamp($stamp1, "file");
 
                $data = getimagesize($tempfile);
 

diff --git a/src/Util/Network.php b/src/Util/Network.php
index de4b45da9a35bcf7c60572b140af0c8ac13b17c6..4d5afa3a362f218b16decfecdcbc09f94a4ed89a 100644 (file)
--- a/src/Util/Network.php
+++ b/src/Util/Network.php
@@ -4,13 +4,13 @@
  */
 namespace Friendica\Util;
 
+use DOMDocument;
+use DomXPath;
+use Friendica\Core\Config;
 use Friendica\Core\Hook;
 use Friendica\Core\Logger;
 use Friendica\Core\System;
-use Friendica\Core\Config;
 use Friendica\Network\CurlResult;
-use DOMDocument;
-use DomXPath;
 
 class Network
 {
@@ -232,7 +232,7 @@ class Network
 
                @curl_close($ch);
 
-               $a->saveTimestamp($stamp1, 'network');
+               $a->getProfiler()->saveTimestamp($stamp1, 'network');
 
                return $curlResponse;
        }
@@ -334,7 +334,7 @@ class Network
 
                curl_close($ch);
 
-               $a->saveTimestamp($stamp1, 'network');
+               $a->getProfiler()->saveTimestamp($stamp1, 'network');
 
                Logger::log('post_url: end ' . $url, Logger::DATA);
 
@@ -641,7 +641,7 @@ class Network
                $http_code = $curl_info['http_code'];
                curl_close($ch);
 
-               $a->saveTimestamp($stamp1, "network");
+               $a->getProfiler()->saveTimestamp($stamp1, "network");
 
                if ($http_code == 0) {
                        return $url;
@@ -683,7 +683,7 @@ class Network
                $body = curl_exec($ch);
                curl_close($ch);
 
-               $a->saveTimestamp($stamp1, "network");
+               $a->getProfiler()->saveTimestamp($stamp1, "network");
 
                if (trim($body) == "") {
                        return $url;

diff --git a/src/Util/Profiler.php b/src/Util/Profiler.php
new file mode 100644 (file)
index 0000000..7bf30a2
--- /dev/null
+++ b/src/Util/Profiler.php
@@ -0,0 +1,252 @@
+<?php
+
+namespace Friendica\Util;
+
+use Friendica\Core;
+use Psr\Container\ContainerExceptionInterface;
+use Psr\Container\ContainerInterface;
+use Psr\Container\NotFoundExceptionInterface;
+use Psr\Log\LoggerInterface;
+
+/**
+ * A class to store profiling data
+ * It can handle different logging data for specific functions or global performance measures
+ *
+ * It stores the data as log entries (@see LoggerInterface )
+ */
+class Profiler implements ContainerInterface
+{
+       /**
+        * @var array The global performance array
+        */
+       private $performance;
+       /**
+        * @var array The function specific callstack
+        */
+       private $callstack;
+       /**
+        * @var bool True, if the Profiler is enabled
+        */
+       private $enabled;
+       /**
+        * @var bool True, if the Profiler should measure the whole rendertime including functions
+        */
+       private $rendertime;
+
+       /**
+        * @var LoggerInterface The profiler logger
+        */
+       private $logger;
+
+       /**
+        * @param LoggerInterface $logger The profiler logger
+        * @param bool $enabled           True, if the Profiler is enabled
+        * @param bool $renderTime        True, if the Profiler should measure the whole rendertime including functions
+        */
+       public function __construct(LoggerInterface $logger, $enabled = false, $renderTime = false)
+       {
+               $this->enabled = $enabled;
+               $this->rendertime = $renderTime;
+               $this->logger = $logger;
+               $this->performance = [];
+               $this->callstack   = [];
+       }
+
+       /**
+        * Saves a timestamp for a value - f.e. a call
+        * Necessary for profiling Friendica
+        *
+        * @param int $timestamp the Timestamp
+        * @param string $value A value to profile
+        */
+       public function saveTimestamp($timestamp, $value)
+       {
+               if (!$this->enabled) {
+                       return;
+               }
+
+               $duration = (float) (microtime(true) - $timestamp);
+
+               if (!isset($this->performance[$value])) {
+                       // Prevent ugly E_NOTICE
+                       $this->performance[$value] = 0;
+               }
+
+               $this->performance[$value] += (float) $duration;
+               $this->performance['marktime'] += (float) $duration;
+
+               $callstack = Core\System::callstack();
+
+               if (!isset($this->callstack[$value][$callstack])) {
+                       // Prevent ugly E_NOTICE
+                       $this->callstack[$value][$callstack] = 0;
+               }
+
+               $this->callstack[$value][$callstack] += (float) $duration;
+       }
+
+       /**
+        * Resets the performance and callstack profiling
+        *
+        * @param bool $performance If true, reset the performance (Default true)
+        * @param bool $callstack   If true, reset the callstack (Default true)
+        */
+       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['markstart'] = microtime(true);
+               }
+
+               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'] = [];
+               }
+       }
+
+       /**
+        * Save the current profiling data to a log entry
+        *
+        * @param string $message Additional message for the log
+        */
+       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["dache"])) {
+                                       $o .= "\nCache Read:\n";
+                                       foreach ($this->callstack["dache"] as $func => $time) {
+                                               $time = round($time, 3);
+                                               if ($time > 0) {
+                                                       $o .= $func.": ".$time."\n";
+                                               }
+                                       }
+                               }
+                               if (isset($this->callstack["dache_write"])) {
+                                       $o .= "\nCache Write:\n";
+                                       foreach ($this->callstack["dache_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 . ": " . sprintf(
+                                       "DB: %s/%s, Cache: %s/%s, Net: %s, I/O: %s, Other: %s, Total: %s".$o,
+                                       number_format($this->get('database') - $this->get('database_write'), 2),
+                                       number_format($this->get('database_write'), 2),
+                                       number_format($this->get('cache'), 2),
+                                       number_format($this->get('cache_write'), 2),
+                                       number_format($this->get('network'), 2),
+                                       number_format($this->get('file'), 2),
+                                       number_format($duration - ($this->get('database')
+                                                       + $this->get('cache') + $this->get('cache_write')
+                                                       + $this->get('network') + $this->get('file')), 2),
+                                       number_format($duration, 2)
+                               )
+                       );
+               }
+       }
+
+       /**
+        * Finds an entry of the container by its identifier and returns it.
+        *
+        * @param string $id Identifier of the entry to look for.
+        *
+        * @throws NotFoundExceptionInterface  No entry was found for **this** identifier.
+        * @throws ContainerExceptionInterface Error while retrieving the entry.
+        *
+        * @return int Entry.
+        */
+       public function get($id)
+       {
+               if (!$this->has($id)) {
+                       return 0;
+               } else {
+                       return $this->performance[$id];
+               }
+       }
+
+       /**
+        * Returns true if the container can return an entry for the given identifier.
+        * Returns false otherwise.
+        *
+        * `has($id)` returning true does not mean that `get($id)` will not throw an exception.
+        * It does however mean that `get($id)` will not throw a `NotFoundExceptionInterface`.
+        *
+        * @param string $id Identifier of the entry to look for.
+        *
+        * @return bool
+        */
+       public function has($id)
+       {
+               return isset($this->performance[$id]);
+       }
+}

diff --git a/tests/DatabaseTest.php b/tests/DatabaseTest.php
index 79af5b5468a9495f86d390ceda58d1afdc4d64eb..5c66711dcf0e6e9d6122b1b639b56a6b93d5da26 100644 (file)
--- a/tests/DatabaseTest.php
+++ b/tests/DatabaseTest.php
@@ -9,6 +9,7 @@ use Friendica\Core\Config;
 use Friendica\Database\DBA;
 use Friendica\Factory;
 use Friendica\Util\BasePath;
+use Friendica\Util\Profiler;
 use PHPUnit\DbUnit\DataSet\YamlDataSet;
 use PHPUnit\DbUnit\TestCaseTrait;
 use PHPUnit_Extensions_Database_DB_IDatabaseConnection;
@@ -43,8 +44,11 @@ abstract class DatabaseTest extends MockedTest
                $configLoader = new Config\ConfigCacheLoader($basedir);
                $config = Factory\ConfigFactory::createCache($configLoader);
 
+               $profiler = \Mockery::mock(Profiler::class);
+
                DBA::connect(
                        $config,
+                       $profiler,
                        getenv('MYSQL_HOST'),
                        getenv('MYSQL_USERNAME'),
                        getenv('MYSQL_PASSWORD'),