From 343803afb9de3b27ba44d9594b6770f9c84d2e54 Mon Sep 17 00:00:00 2001 From: Michael Foster Date: Fri, 30 Aug 2013 08:39:11 +1000 Subject: [PATCH] More $config['debug'] improvements to time-related stuff --- inc/cache.php | 2 +- inc/database.php | 21 +++++++++++++++------ inc/functions.php | 32 ++++++++++++++++++++++---------- inc/template.php | 6 ++++-- mod.php | 6 +++++- 5 files changed, 47 insertions(+), 20 deletions(-) diff --git a/inc/cache.php b/inc/cache.php index fd89be13..2f3c746c 100644 --- a/inc/cache.php +++ b/inc/cache.php @@ -66,7 +66,7 @@ class Cache { return $data; } public static function set($key, $value, $expires = false) { - global $config; + global $config, $debug; $key = $config['cache']['prefix'] . $key; diff --git a/inc/database.php b/inc/database.php index 8daa20b4..55e1ff81 100644 --- a/inc/database.php +++ b/inc/database.php @@ -28,13 +28,13 @@ class PreparedQueryDebug { $return = call_user_func_array(array($this->query, $function), $args); if ($config['debug'] && $function == 'execute') { - $time = round((microtime(true) - $start) * 1000, 2) . 'ms'; - + $time = microtime(true) - $start; $debug['sql'][] = array( 'query' => $this->query->queryString, 'rows' => $this->query->rowCount(), - 'time' => '~' . $time + 'time' => '~' . round($time * 1000, 2) . 'ms' ); + $debug['time']['db_queries'] += $time; } return $return; @@ -42,10 +42,14 @@ class PreparedQueryDebug { } function sql_open() { - global $pdo, $config; + global $pdo, $config, $debug; if ($pdo) return true; + + if ($config['debug']) + $start = microtime(true); + if (isset($config['db']['server'][0]) && $config['db']['server'][0] == ':') $unix_socket = substr($config['db']['server'], 1); else @@ -64,6 +68,10 @@ function sql_open() { if ($config['db']['persistent']) $options[PDO::ATTR_PERSISTENT] = true; $pdo = new PDO($dsn, $config['db']['user'], $config['db']['password'], $options); + + if ($config['debug']) + $debug['time']['db_connect'] = '~' . round((microtime(true) - $start) * 1000, 2) . 'ms'; + if (mysql_version() >= 50503) query('SET NAMES utf8mb4') or error(db_error()); else @@ -117,12 +125,13 @@ function query($query) { $query = $pdo->query($query); if (!$query) return false; - $time = round((microtime(true) - $start) * 1000, 2) . 'ms'; + $time = microtime(true) - $start; $debug['sql'][] = array( 'query' => $query->queryString, 'rows' => $query->rowCount(), - 'time' => '~' . $time + 'time' => '~' . round($time * 1000, 2) . 'ms' ); + $debug['time']['db_queries'] += $time; return $query; } diff --git a/inc/functions.php b/inc/functions.php index e634b87e..6c18ce3e 100644 --- a/inc/functions.php +++ b/inc/functions.php @@ -81,14 +81,6 @@ function loadConfig() { $__version = file_exists('.installed') ? trim(file_get_contents('.installed')) : false; $config['version'] = $__version; - if ($config['debug']) { - if (!isset($debug)) { - $debug = array('sql' => array(), 'exec' => array(), 'purge' => array(), 'cached' => array(), 'write' => array()); - $debug['start'] = $microtime_start; - $debug['start_debug'] = microtime(true);; - } - } - date_default_timezone_set($config['timezone']); if (!isset($config['global_message'])) @@ -199,6 +191,25 @@ function loadConfig() { if ($config['cache']['enabled']) require_once 'inc/cache.php'; event('load-config'); + + if ($config['debug']) { + if (!isset($debug)) { + $debug = array( + 'sql' => array(), + 'exec' => array(), + 'purge' => array(), + 'cached' => array(), + 'write' => array(), + 'time' => array( + 'db_queries' => 0, + 'exec' => 0, + ), + 'start' => $microtime_start, + 'start_debug' => microtime(true) + ); + $debug['start'] = $microtime_start; + } + } } function basic_error_function_because_the_other_isnt_loaded_yet($message, $priority = true) { @@ -2056,12 +2067,13 @@ function shell_exec_error($command, $suppress_stdout = false) { $return = preg_replace('/TB_SUCCESS$/', '', $return); if ($config['debug']) { - $time = round((microtime(true) - $start) * 1000, 2) . 'ms'; + $time = microtime(true) - $start; $debug['exec'][] = array( 'command' => $command, - 'time' => '~' . $time, + 'time' => '~' . round($time * 1000, 2) . 'ms', 'response' => $return ? $return : null ); + $debug['time']['exec'] += $time; } return $return === 'TB_SUCCESS' ? false : $return; diff --git a/inc/template.php b/inc/template.php index 6d417631..d9e1c386 100644 --- a/inc/template.php +++ b/inc/template.php @@ -46,8 +46,8 @@ function Element($templateFile, array $options) { if (isset($options['body']) && $config['debug']) { if (isset($debug['start'])) { - $debug['time'] = '~' . round((microtime(true) - $debug['start']) * 1000, 2) . 'ms'; - $debug['time (initialization)'] = '~' . round(($debug['start_debug'] - $debug['start']) * 1000, 2) . 'ms'; + $debug['time']['total'] = '~' . round((microtime(true) - $debug['start']) * 1000, 2) . 'ms'; + $debug['time']['init'] = '~' . round(($debug['start_debug'] - $debug['start']) * 1000, 2) . 'ms'; unset($debug['start']); unset($debug['start_debug']); } @@ -55,6 +55,8 @@ function Element($templateFile, array $options) { $debug['build_pages'] = $build_pages; $debug['included'] = get_included_files(); $debug['memory'] = round(memory_get_usage(true) / (1024 * 1024), 2) . ' MiB'; + $debug['time']['db_queries'] = '~' . round($debug['time']['db_queries'] * 1000, 2) . 'ms'; + $debug['time']['exec'] = '~' . round($debug['time']['exec'] * 1000, 2) . 'ms'; $options['body'] .= '

Debug

' .
 				str_replace("\n", '
', utf8tohtml(print_r($debug, true))) . diff --git a/mod.php b/mod.php index 0e98c4eb..6ef4644d 100644 --- a/mod.php +++ b/mod.php @@ -8,6 +8,9 @@ require 'inc/functions.php'; require 'inc/mod/pages.php'; require 'inc/mod/auth.php'; +if ($config['debug']) + $parse_start_time = microtime(true); + // Fix for magic quotes if (get_magic_quotes_gpc()) { function strip_array($var) { @@ -156,8 +159,9 @@ foreach ($pages as $uri => $handler) { $debug['mod_page'] = array( 'req' => $query, 'match' => $uri, - 'handler' => $handler + 'handler' => $handler, ); + $debug['time']['parse_mod_req'] = '~' . round((microtime(true) - $parse_start_time) * 1000, 2) . 'ms'; } if (is_string($handler)) {