From c2fd9e955a86cfb47766bd72f0850fc5e0b249c0 Mon Sep 17 00:00:00 2001 From: martinlanghoff Date: Wed, 6 Apr 2005 07:34:05 +0000 Subject: [PATCH] Improved performance info reporting and logging. Needs some work on the configuration front still. --- lib/moodlelib.php | 82 +++++++++++++++++++++++++++++++++++++++-------- lib/setup.php | 55 ++++++++++++++++--------------- lib/weblib.php | 14 ++++---- 3 files changed, 106 insertions(+), 45 deletions(-) diff --git a/lib/moodlelib.php b/lib/moodlelib.php index 0998c5039a1..3f1cb704496 100644 --- a/lib/moodlelib.php +++ b/lib/moodlelib.php @@ -5648,27 +5648,81 @@ function bounded_number($min, $value, $max) { } -function collect_performance_info() { - global $CFG; - - $CFG->startpagetime = microtime(); -} - +/** + *** get_performance_info() pairs up with init_performance_info() + *** loaded in setup.php. Returns an array with 'html' and 'txt' + *** values ready for use, and each of the individual stats provided + *** separately as well. + *** + **/ function get_performance_info() { - global $CFG; + global $CFG, $PERF; + + $info = array(); + $info['html'] = $_SERVER['REQUEST_URI'] . ' '; // holds userfriendly HTML representation + $info['txt'] = $_SERVER['REQUEST_URI'] . ' '; // holds log-friendly representation + + $info['realtime'] = microtime_diff($PERF->starttime, microtime()); + + $info['html'] .= ''.$info['realtime'].' secs '; + $info['txt'] .= 'time: '.$info['realtime'].'s '; - $info = ''; if (function_exists('memory_get_usage')) { - $info .= ''.$_SERVER['REQUEST_URI'].' RAM: '.memory_get_usage().''; - } - if (isset($CFG->startpagetime)) { - $info .= ''.microtime_diff($CFG->startpagetime, microtime()).' secs'; + $info['memory_total'] = memory_get_usage(); + $info['memory_growth'] = memory_get_usage() - $PERF->startmemory; + $info['html'] .= 'RAM: '.display_size($info['memory_total']).' '; + $info['txt'] .= 'memory_total: '.$info['memory_total'].'B (' . display_size($info['memory_total']).') memory_growth: '.$info['memory_growth'].'B ('.display_size($info['memory_growth']).') '; } - if ($info) { - return '
'.$info.'
'; + $inc = get_included_files(); + //error_log(print_r($inc,1)); + $info['includecount'] = count($inc); + $info['html'] .= 'Included '.$info['includecount'].' files '; + $info['txt'] .= 'includecount: '.$info['includecount'].' '; + + if (!empty($PERF->dbqueries)) { + $info['dbqueries'] = $PERF->dbqueries; + $info['html'] .= 'DB queries'.$info['dbqueries'].' '; + $info['txt'] .= 'dbqueries: '.$info['dbqueries'].' '; } + if (!empty($PERF->logwrites)) { + $info['logwrites'] = $PERF->logwrites; + $info['html'] .= 'Log writes '.$info['logwrites'].' '; + $info['txt'] .= 'logwrites: '.$info['logwrites'].' '; + } + + if (function_exists('posix_times')) { + $ptimes = posix_times(); + foreach ($ptimes as $key => $val) { + $info[$key] = $ptimes[$key] - $PERF->startposixtimes[$key]; + } + $info['html'] .= "ticks: $info[ticks] user: $info[utime] sys: $info[stime] cuser: $info[cutime] csys: $info[cstime] "; + $info['txt'] .= "ticks: $info[ticks] user: $info[utime] sys: $info[stime] cuser: $info[cutime] csys: $info[cstime] "; + + } + + // Grab the load average for the last minute + // /proc will only work under some linux configurations + // while uptime is there under MacOSX/Darwin and other unices + if (is_readable('/proc/loadavg') && $loadavg = @file('/proc/loadavg')) { + list($server_load) = explode(' ', $loadavg[0]); + unset($loadavg); + } else if ( is_executable('/usr/bin/uptime') && $loadavg = `/usr/bin/uptime` ) { + if (preg_match('/load averages?: (\d+:\d+)/', $loadavg, $matches)) { + $server_load = $matches[1]; + } else { + trigger_error('Could not parse uptime output!'); + } + } + if (!empty($server_load)) { + $info['serverload'] = $server_load; + $info['html'] .= 'Load average: '.$info['serverload'].'% '; + $info['txt'] .= 'serverload: '.$info['serverload'].'% '; + } + + + $info['html'] = '
'.$info['html'].''; return $info; } diff --git a/lib/setup.php b/lib/setup.php index 3bd2299e82b..4052db131dd 100644 --- a/lib/setup.php +++ b/lib/setup.php @@ -69,32 +69,9 @@ global $THEME; die; } -/// Time to start counting - $PERF = new Object; +/// Time to start counting if(!empty($CFG->perfdebug)) { - - if (function_exists('microtime')) { - $PERF->starttime = microtime(); - } - if (function_exists('memory_get_usage')) { - $PERF->startmemory = memory_get_usage(); - } - if (function_exists('posix_times')) { - $PERF->startposixtimes = posix_times(); - } - // Grab the load average for the last minute - // /proc will only work under some linux configurations - // while uptime is there under MacOSX/Darwin and other unices - if (is_readable('/proc/loadavg') && $loadavg = @file('/proc/loadavg')) { - list($PERF->server_load) = explode(' ', $loadavg[0]); - unset($loadavg); - } else if ( is_executable('/usr/bin/uptime') && $loadavg = `/usr/bin/uptime` ) { - if (preg_match('/load averages?: (\d+:\d+)/', $loadavg, $matches)) { - $PERF->server_load = $matches[1]; - } else { - trigger_error('Could not parse uptime output!'); - } - } + init_performance_info(); } /// If there are any errors in the standard libraries we want to know! @@ -409,4 +386,32 @@ global $THEME; } } +/*** + *** init_performance_info() { + *** + *** Initializes our performance info early. + *** + *** Pairs up with get_performance_info() which is actually + *** in moodlelib.php. This function is here so that we can + *** call it before all the libs are pulled in. + *** + **/ +function init_performance_info() { + + global $PERF; + + $PERF = new Object; + $PERF->dbqueries = 0; + $PERF->logwrites = 0; + if (function_exists('microtime')) { + $PERF->starttime = microtime(); + } + if (function_exists('memory_get_usage')) { + $PERF->startmemory = memory_get_usage(); + } + if (function_exists('posix_times')) { + $PERF->startposixtimes = posix_times(); + } +} + ?> diff --git a/lib/weblib.php b/lib/weblib.php index a20c74cf871..34b7bd7a36b 100644 --- a/lib/weblib.php +++ b/lib/weblib.php @@ -1834,12 +1834,14 @@ function print_footer($course=NULL, $usercourse=NULL) { } /// Provide some performance info if required - - if ($CFG->debug > 7) { - $performanceinfo = get_performance_info(); - } else { - $performanceinfo = ''; - } + $performanceinfo = ''; + if (!empty($CFG->perfdebug)) { + $perf = get_performance_info(); + error_log("PERF: " . $perf['txt']); + if ($CFG->debug > 7) { + $performanceinfo = $perf['html']; + } + } /// Include the actual footer file