/** * Measures operations duration, memory usage, etc. (and some other KPIs) * * @copyright Copyright (C) 2010-2012 Combodo SARL * @license http://opensource.org/licenses/AGPL-3.0 */ class ExecutionKPI { static protected $m_bEnabled_Duration = false; static protected $m_bEnabled_Memory = false; static protected $m_sAllowedUser = '*'; static protected $m_aStats = array(); // Recurrent operations static protected $m_aExecData = array(); // One shot operations protected $m_fStarted = null; protected $m_iInitialMemory = null; static public function EnableDuration($iLevel) { if ($iLevel > 0) { self::$m_bEnabled_Duration = true; } } static public function EnableMemory($iLevel) { if ($iLevel > 0) { self::$m_bEnabled_Memory = true; } } /** * @param string sUser A user login or * for all users */ static public function SetAllowedUser($sUser) { self::$m_sAllowedUser = $sUser; } static public function ReportStats() { if (self::$m_sAllowedUser != '*') { if (UserRights::GetUser() != self::$m_sAllowedUser) { return; } } global $fItopStarted; $sExecId = microtime(); // id to differentiate the hrefs! $aBeginTimes = array(); foreach (self::$m_aExecData as $aOpStats) { $aBeginTimes[] = $aOpStats['time_begin']; } array_multisort($aBeginTimes, self::$m_aExecData); $sTableStyle = 'background-color: #ccc; margin: 10px;'; self::Report("
"); self::Report("
"); self::Report("

KPIs - ".$_SERVER['REQUEST_URI']." (".$_SERVER['REQUEST_METHOD'].")

"); self::Report("

".date('Y-m-d H:i:s', $fItopStarted)."

"); self::Report("

log_kpi_user_id: ".MetaModel::GetConfig()->Get('log_kpi_user_id')."

"); self::Report("
"); self::Report(""); self::Report(""); self::Report(" "); self::Report(""); foreach (self::$m_aExecData as $aOpStats) { $sOperation = $aOpStats['op']; $sBegin = $sEnd = $sDuration = $sMemBegin = $sMemEnd = $sMemPeak = '?'; $sBegin = round($aOpStats['time_begin'], 3); $sEnd = round($aOpStats['time_end'], 3); $fDuration = $aOpStats['time_end'] - $aOpStats['time_begin']; $sDuration = round($fDuration, 3); if (isset($aOpStats['mem_begin'])) { $sMemBegin = self::MemStr($aOpStats['mem_begin']); $sMemEnd = self::MemStr($aOpStats['mem_end']); if (isset($aOpStats['mem_peak'])) { $sMemPeak = self::MemStr($aOpStats['mem_peak']); } } self::Report(""); self::Report(" "); self::Report(""); } self::Report("
OperationBeginEndDurationMemory startMemory endMemory peak
$sOperation$sBegin$sEnd$sDuration$sMemBegin$sMemEnd$sMemPeak
"); self::Report("
"); $aConsolidatedStats = array(); foreach (self::$m_aStats as $sOperation => $aOpStats) { $fTotalOp = 0; $iTotalOp = 0; $fMinOp = null; $fMaxOp = 0; $sMaxOpArguments = null; foreach ($aOpStats as $sArguments => $aEvents) { foreach ($aEvents as $fDuration) { $fTotalOp += $fDuration; $iTotalOp++; $fMinOp = is_null($fMinOp) ? $fDuration : min($fMinOp, $fDuration); if ($fDuration > $fMaxOp) { $sMaxOpArguments = $sArguments; $fMaxOp = $fDuration; } } } $aConsolidatedStats[$sOperation] = array( 'count' => $iTotalOp, 'duration' => $fTotalOp, 'min' => $fMinOp, 'max' => $fMaxOp, 'avg' => $fTotalOp / $iTotalOp, 'max_args' => $sMaxOpArguments ); } self::Report("
"); self::Report(""); self::Report(""); self::Report(" "); self::Report(""); foreach ($aConsolidatedStats as $sOperation => $aOpStats) { $sOperation = ''.$sOperation.''; $sCount = $aOpStats['count']; $sDuration = round($aOpStats['duration'], 3); $sMin = round($aOpStats['min'], 3); $sMax = ''.round($aOpStats['max'], 3).''; $sAvg = round($aOpStats['avg'], 3); self::Report(""); self::Report(" "); self::Report(""); } self::Report("
OperationCountDurationMinMaxAvg
$sOperation$sCount$sDuration$sMin$sMax$sAvg
"); self::Report("
"); self::Report("
"); // Report operation details foreach (self::$m_aStats as $sOperation => $aOpStats) { $sOperationHtml = ''.$sOperation.''; self::Report("

$sOperationHtml

"); self::Report("

Back to page stats

"); self::Report(""); self::Report(""); self::Report(" "); self::Report(""); foreach ($aOpStats as $sArguments => $aEvents) { $sHtmlArguments = ''.$sArguments.''; if ($aConsolidatedStats[$sOperation]['max_args'] == $sArguments) { $sHtmlArguments = ''.$sHtmlArguments.''; } $fTotalInter = 0; $fMinInter = null; $fMaxInter = 0; foreach ($aEvents as $fDuration) { $fTotalInter += $fDuration; $fMinInter = is_null($fMinInter) ? $fDuration : min($fMinInter, $fDuration); $fMaxInter = max($fMaxInter, $fDuration); } $iCountInter = count($aEvents); $sTotalInter = round($fTotalInter, 3); $sMinInter = round($fMinInter, 3); $sMaxInter = round($fMaxInter, 3); self::Report(""); self::Report(" "); self::Report(""); } self::Report("
Operation detailsCountDurationMinMax
$sHtmlArguments$iCountInter$sTotalInter$sMinInter$sMaxInter
"); } } public function __construct() { $this->ResetCounters(); } // Get the duration since startup, and reset the counter for the next measure // public function ComputeAndReport($sOperationDesc) { global $fItopStarted; $aNewEntry = null; if (self::$m_bEnabled_Duration) { $fStopped = MyHelpers::getmicrotime(); $aNewEntry = array( 'op' => $sOperationDesc, 'time_begin' => $this->m_fStarted - $fItopStarted, 'time_end' => $fStopped - $fItopStarted, ); // Reset for the next operation (if the object is recycled) $this->m_fStarted = $fStopped; } if (self::$m_bEnabled_Memory) { $iCurrentMemory = self::memory_get_usage(); if (is_null($aNewEntry)) { $aNewEntry = array('op' => $sOperationDesc); } $aNewEntry['mem_begin'] = $this->m_iInitialMemory; $aNewEntry['mem_end'] = $iCurrentMemory; if (function_exists('memory_get_peak_usage')) { $aNewEntry['mem_peak'] = memory_get_peak_usage(); } // Reset for the next operation (if the object is recycled) $this->m_iInitialMemory = $iCurrentMemory; } if (!is_null($aNewEntry)) { self::$m_aExecData[] = $aNewEntry; } $this->ResetCounters(); } public function ComputeStats($sOperation, $sArguments) { if (self::$m_bEnabled_Duration) { $fStopped = MyHelpers::getmicrotime(); $fDuration = $fStopped - $this->m_fStarted; self::$m_aStats[$sOperation][$sArguments][] = $fDuration; } } protected function ResetCounters() { if (self::$m_bEnabled_Duration) { $this->m_fStarted = MyHelpers::getmicrotime(); } if (self::$m_bEnabled_Memory) { $this->m_iInitialMemory = self::memory_get_usage(); } } const HtmlReportFile = 'log/kpi.html'; static protected function Report($sText) { file_put_contents(APPROOT.self::HtmlReportFile, "$sText\n", FILE_APPEND | LOCK_EX); } static protected function MemStr($iMemory) { return round($iMemory / 1024).' Kb'; } static protected function memory_get_usage() { if (function_exists('memory_get_usage')) { return memory_get_usage(true); } // Copied from the PHP manual // //If its Windows //Tested on Win XP Pro SP2. Should work on Win 2003 Server too //Doesn't work for 2000 //If you need it to work for 2000 look at http://us2.php.net/manual/en/function.memory-get-usage.php#54642 if (substr(PHP_OS,0,3) == 'WIN') { $output = array(); exec('tasklist /FI "PID eq ' . getmypid() . '" /FO LIST', $output); return preg_replace( '/[\D]/', '', $output[5] ) * 1024; } else { //We now assume the OS is UNIX //Tested on Mac OS X 10.4.6 and Linux Red Hat Enterprise 4 //This should work on most UNIX systems $pid = getmypid(); exec("ps -eo%mem,rss,pid | grep $pid", $output); $output = explode(" ", $output[0]); //rss is given in 1024 byte units return $output[1] * 1024; } } static public function memory_get_peak_usage($bRealUsage = false) { if (function_exists('memory_get_peak_usage')) { return memory_get_peak_usage($bRealUsage); } // PHP > 5.2.1 - this verb depends on a compilation option return 0; } }