/**
* 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_bBlameCaller = 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;
if ($iLevel > 1)
{
self::$m_bBlameCaller = 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 IsEnabled()
{
if (self::$m_bEnabled_Duration || self::$m_bEnabled_Memory)
{
if ((self::$m_sAllowedUser == '*') || (UserRights::GetUser() == trim(self::$m_sAllowedUser)))
{
return true;
}
}
return false;
}
static public function GetDescription()
{
$aFeatures = array();
if (self::$m_bEnabled_Duration) $aFeatures[] = 'Duration';
if (self::$m_bEnabled_Memory) $aFeatures[] = 'Memory usage';
$sFeatures = implode(', ', $aFeatures);
$sFor = self::$m_sAllowedUser == '*' ? 'EVERYBODY' : "'".trim(self::$m_sAllowedUser)."'";
return "KPI logging is active for $sFor. Measures: $sFeatures";
}
static public function ReportStats()
{
if (!self::IsEnabled()) 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(" Operation | Begin | End | Duration | Memory start | Memory end | Memory peak | ");
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(" $sOperation | $sBegin | $sEnd | $sDuration | $sMemBegin | $sMemEnd | $sMemPeak | ");
self::Report("
");
}
self::Report("
");
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 $aEventData)
{
$fDuration = $aEventData['time'];
$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(" Operation | Count | Duration | Min | Max | Avg | ");
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(" $sOperation | $sCount | $sDuration | $sMin | $sMax | $sAvg | ");
self::Report("
");
}
self::Report("
");
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(" Operation details (+ blame caller if log_kpi_duration = 2) | Count | Duration | Min | Max | ");
self::Report("");
foreach ($aOpStats as $sArguments => $aEvents)
{
$sHtmlArguments = ''.$sArguments.'
';
if ($aConsolidatedStats[$sOperation]['max_args'] == $sArguments)
{
$sHtmlArguments = ''.$sHtmlArguments.'';
}
if (isset($aEvents[0]['callers']))
{
$sHtmlArguments .= '';
$sHtmlArguments .= '
';
$sHtmlArguments .= 'Call stack for the FIRST caller |
';
foreach ($aEvents[0]['callers'] as $aCall)
{
$sHtmlArguments .= '';
$sHtmlArguments .= ''.$aCall['Function'].' | ';
$sHtmlArguments .= ''.$aCall['File'].':'.$aCall['Line'].' | ';
$sHtmlArguments .= '
';
}
$sHtmlArguments .= '
';
$sHtmlArguments .= '
';
}
$fTotalInter = 0;
$fMinInter = null;
$fMaxInter = 0;
foreach ($aEvents as $aEventData)
{
$fDuration = $aEventData['time'];
$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(" $sHtmlArguments | $iCountInter | $sTotalInter | $sMinInter | $sMaxInter | ");
self::Report("
");
}
self::Report("
");
}
}
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;
if (self::$m_bBlameCaller)
{
self::$m_aStats[$sOperation][$sArguments][] = array(
'time' => $fDuration,
'callers' => MyHelpers::get_callstack(1),
);
}
else
{
self::$m_aStats[$sOperation][$sArguments][] = array(
'time' => $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;
}
}