1<?php 2// Copyright (C) 2010-2012 Combodo SARL 3// 4// This file is part of iTop. 5// 6// iTop is free software; you can redistribute it and/or modify 7// it under the terms of the GNU Affero General Public License as published by 8// the Free Software Foundation, either version 3 of the License, or 9// (at your option) any later version. 10// 11// iTop is distributed in the hope that it will be useful, 12// but WITHOUT ANY WARRANTY; without even the implied warranty of 13// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the 14// GNU Affero General Public License for more details. 15// 16// You should have received a copy of the GNU Affero General Public License 17// along with iTop. If not, see <http://www.gnu.org/licenses/> 18 19 20/** 21 * Measures operations duration, memory usage, etc. (and some other KPIs) 22 * 23 * @copyright Copyright (C) 2010-2012 Combodo SARL 24 * @license http://opensource.org/licenses/AGPL-3.0 25 */ 26 27class ExecutionKPI 28{ 29 static protected $m_bEnabled_Duration = false; 30 static protected $m_bEnabled_Memory = false; 31 static protected $m_bBlameCaller = false; 32 static protected $m_sAllowedUser = '*'; 33 34 static protected $m_aStats = array(); // Recurrent operations 35 static protected $m_aExecData = array(); // One shot operations 36 37 protected $m_fStarted = null; 38 protected $m_iInitialMemory = null; 39 40 static public function EnableDuration($iLevel) 41 { 42 if ($iLevel > 0) 43 { 44 self::$m_bEnabled_Duration = true; 45 if ($iLevel > 1) 46 { 47 self::$m_bBlameCaller = true; 48 } 49 } 50 } 51 52 static public function EnableMemory($iLevel) 53 { 54 if ($iLevel > 0) 55 { 56 self::$m_bEnabled_Memory = true; 57 } 58 } 59 60 /** 61 * @param string sUser A user login or * for all users 62 */ 63 static public function SetAllowedUser($sUser) 64 { 65 self::$m_sAllowedUser = $sUser; 66 } 67 68 static public function IsEnabled() 69 { 70 if (self::$m_bEnabled_Duration || self::$m_bEnabled_Memory) 71 { 72 if ((self::$m_sAllowedUser == '*') || (UserRights::GetUser() == trim(self::$m_sAllowedUser))) 73 { 74 return true; 75 } 76 } 77 return false; 78 } 79 80 static public function GetDescription() 81 { 82 $aFeatures = array(); 83 if (self::$m_bEnabled_Duration) $aFeatures[] = 'Duration'; 84 if (self::$m_bEnabled_Memory) $aFeatures[] = 'Memory usage'; 85 $sFeatures = implode(', ', $aFeatures); 86 $sFor = self::$m_sAllowedUser == '*' ? 'EVERYBODY' : "'".trim(self::$m_sAllowedUser)."'"; 87 return "KPI logging is active for $sFor. Measures: $sFeatures"; 88 } 89 90 static public function ReportStats() 91 { 92 if (!self::IsEnabled()) return; 93 94 global $fItopStarted; 95 $sExecId = microtime(); // id to differentiate the hrefs! 96 97 $aBeginTimes = array(); 98 foreach (self::$m_aExecData as $aOpStats) 99 { 100 $aBeginTimes[] = $aOpStats['time_begin']; 101 } 102 array_multisort($aBeginTimes, self::$m_aExecData); 103 104 $sTableStyle = 'background-color: #ccc; margin: 10px;'; 105 106 self::Report("<hr/>"); 107 self::Report("<div style=\"background-color: grey; padding: 10px;\">"); 108 self::Report("<h3><a name=\"".md5($sExecId)."\">KPIs</a> - ".$_SERVER['REQUEST_URI']." (".$_SERVER['REQUEST_METHOD'].")</h3>"); 109 self::Report("<p>".date('Y-m-d H:i:s', $fItopStarted)."</p>"); 110 self::Report("<p>log_kpi_user_id: ".UserRights::GetUserId()."</p>"); 111 self::Report("<div>"); 112 self::Report("<table border=\"1\" style=\"$sTableStyle\">"); 113 self::Report("<thead>"); 114 self::Report(" <th>Operation</th><th>Begin</th><th>End</th><th>Duration</th><th>Memory start</th><th>Memory end</th><th>Memory peak</th>"); 115 self::Report("</thead>"); 116 foreach (self::$m_aExecData as $aOpStats) 117 { 118 $sOperation = $aOpStats['op']; 119 $sBegin = round($aOpStats['time_begin'], 3); 120 $sEnd = round($aOpStats['time_end'], 3); 121 $fDuration = $aOpStats['time_end'] - $aOpStats['time_begin']; 122 $sDuration = round($fDuration, 3); 123 124 $sMemBegin = 'n/a'; 125 $sMemEnd = 'n/a'; 126 $sMemPeak = 'n/a'; 127 if (isset($aOpStats['mem_begin'])) 128 { 129 $sMemBegin = self::MemStr($aOpStats['mem_begin']); 130 $sMemEnd = self::MemStr($aOpStats['mem_end']); 131 if (isset($aOpStats['mem_peak'])) 132 { 133 $sMemPeak = self::MemStr($aOpStats['mem_peak']); 134 } 135 } 136 137 self::Report("<tr>"); 138 self::Report(" <td>$sOperation</td><td>$sBegin</td><td>$sEnd</td><td>$sDuration</td><td>$sMemBegin</td><td>$sMemEnd</td><td>$sMemPeak</td>"); 139 self::Report("</tr>"); 140 } 141 self::Report("</table>"); 142 self::Report("</div>"); 143 144 $aConsolidatedStats = array(); 145 foreach (self::$m_aStats as $sOperation => $aOpStats) 146 { 147 $fTotalOp = 0; 148 $iTotalOp = 0; 149 $fMinOp = null; 150 $fMaxOp = 0; 151 $sMaxOpArguments = null; 152 foreach ($aOpStats as $sArguments => $aEvents) 153 { 154 foreach ($aEvents as $aEventData) 155 { 156 $fDuration = $aEventData['time']; 157 $fTotalOp += $fDuration; 158 $iTotalOp++; 159 160 $fMinOp = is_null($fMinOp) ? $fDuration : min($fMinOp, $fDuration); 161 if ($fDuration > $fMaxOp) 162 { 163 $sMaxOpArguments = $sArguments; 164 $fMaxOp = $fDuration; 165 } 166 } 167 } 168 $aConsolidatedStats[$sOperation] = array( 169 'count' => $iTotalOp, 170 'duration' => $fTotalOp, 171 'min' => $fMinOp, 172 'max' => $fMaxOp, 173 'avg' => $fTotalOp / $iTotalOp, 174 'max_args' => $sMaxOpArguments 175 ); 176 } 177 178 self::Report("<div>"); 179 self::Report("<table border=\"1\" style=\"$sTableStyle\">"); 180 self::Report("<thead>"); 181 self::Report(" <th>Operation</th><th>Count</th><th>Duration</th><th>Min</th><th>Max</th><th>Avg</th>"); 182 self::Report("</thead>"); 183 foreach ($aConsolidatedStats as $sOperation => $aOpStats) 184 { 185 $sOperation = '<a href="#'.md5($sExecId.$sOperation).'">'.$sOperation.'</a>'; 186 $sCount = $aOpStats['count']; 187 $sDuration = round($aOpStats['duration'], 3); 188 $sMin = round($aOpStats['min'], 3); 189 $sMax = '<a href="#'.md5($sExecId.$aOpStats['max_args']).'">'.round($aOpStats['max'], 3).'</a>'; 190 $sAvg = round($aOpStats['avg'], 3); 191 192 self::Report("<tr>"); 193 self::Report(" <td>$sOperation</td><td>$sCount</td><td>$sDuration</td><td>$sMin</td><td>$sMax</td><td>$sAvg</td>"); 194 self::Report("</tr>"); 195 } 196 self::Report("</table>"); 197 self::Report("</div>"); 198 199 self::Report("</div>"); 200 201 self::Report("<p><a href=\"#end-".md5($sExecId)."\">Next page stats</a></p>"); 202 203 // Report operation details 204 foreach (self::$m_aStats as $sOperation => $aOpStats) 205 { 206 $sOperationHtml = '<a name="'.md5($sExecId.$sOperation).'">'.$sOperation.'</a>'; 207 self::Report("<h4>$sOperationHtml</h4>"); 208 self::Report("<table border=\"1\" style=\"$sTableStyle\">"); 209 self::Report("<thead>"); 210 self::Report(" <th>Operation details (+ blame caller if log_kpi_duration = 2)</th><th>Count</th><th>Duration</th><th>Min</th><th>Max</th>"); 211 self::Report("</thead>"); 212 foreach ($aOpStats as $sArguments => $aEvents) 213 { 214 $sHtmlArguments = '<a name="'.md5($sExecId.$sArguments).'"><div style="white-space: pre-wrap;">'.$sArguments.'</div></a>'; 215 if ($aConsolidatedStats[$sOperation]['max_args'] == $sArguments) 216 { 217 $sHtmlArguments = '<span style="color: red;">'.$sHtmlArguments.'</span>'; 218 } 219 if (isset($aEvents[0]['callers'])) 220 { 221 $sHtmlArguments .= '<div style="padding: 10px;">'; 222 $sHtmlArguments .= '<table border="1" bgcolor="#cfc">'; 223 $sHtmlArguments .= '<tr><td colspan="2" bgcolor="#e9b96">Call stack for the <b>FIRST</b> caller</td></tr>'; 224 225 foreach ($aEvents[0]['callers'] as $aCall) 226 { 227 $sHtmlArguments .= '<tr>'; 228 $sHtmlArguments .= '<td>'.$aCall['Function'].'</td>'; 229 $sHtmlArguments .= '<td>'.$aCall['File'].':'.$aCall['Line'].'</td>'; 230 $sHtmlArguments .= '</tr>'; 231 } 232 $sHtmlArguments .= '</table>'; 233 $sHtmlArguments .= '</div>'; 234 } 235 236 $fTotalInter = 0; 237 $fMinInter = null; 238 $fMaxInter = 0; 239 foreach ($aEvents as $aEventData) 240 { 241 $fDuration = $aEventData['time']; 242 $fTotalInter += $fDuration; 243 $fMinInter = is_null($fMinInter) ? $fDuration : min($fMinInter, $fDuration); 244 $fMaxInter = max($fMaxInter, $fDuration); 245 } 246 247 $iCountInter = count($aEvents); 248 $sTotalInter = round($fTotalInter, 3); 249 $sMinInter = round($fMinInter, 3); 250 $sMaxInter = round($fMaxInter, 3); 251 self::Report("<tr>"); 252 self::Report(" <td>$sHtmlArguments</td><td>$iCountInter</td><td>$sTotalInter</td><td>$sMinInter</td><td>$sMaxInter</td>"); 253 self::Report("</tr>"); 254 } 255 self::Report("</table>"); 256 self::Report("<p><a href=\"#".md5($sExecId)."\">Back to page stats</a></p>"); 257 } 258 self::Report('<a name="end-'.md5($sExecId).'"> </a>'); 259 } 260 261 262 public function __construct() 263 { 264 $this->ResetCounters(); 265 } 266 267 // Get the duration since startup, and reset the counter for the next measure 268 // 269 public function ComputeAndReport($sOperationDesc) 270 { 271 global $fItopStarted; 272 273 $aNewEntry = null; 274 275 if (self::$m_bEnabled_Duration) 276 { 277 $fStopped = MyHelpers::getmicrotime(); 278 $aNewEntry = array( 279 'op' => $sOperationDesc, 280 'time_begin' => $this->m_fStarted - $fItopStarted, 281 'time_end' => $fStopped - $fItopStarted, 282 ); 283 // Reset for the next operation (if the object is recycled) 284 $this->m_fStarted = $fStopped; 285 } 286 287 if (self::$m_bEnabled_Memory) 288 { 289 $iCurrentMemory = self::memory_get_usage(); 290 if (is_null($aNewEntry)) 291 { 292 $aNewEntry = array('op' => $sOperationDesc); 293 } 294 $aNewEntry['mem_begin'] = $this->m_iInitialMemory; 295 $aNewEntry['mem_end'] = $iCurrentMemory; 296 if (function_exists('memory_get_peak_usage')) 297 { 298 $aNewEntry['mem_peak'] = memory_get_peak_usage(); 299 } 300 // Reset for the next operation (if the object is recycled) 301 $this->m_iInitialMemory = $iCurrentMemory; 302 } 303 304 if (!is_null($aNewEntry)) 305 { 306 self::$m_aExecData[] = $aNewEntry; 307 } 308 $this->ResetCounters(); 309 } 310 311 public function ComputeStats($sOperation, $sArguments) 312 { 313 if (self::$m_bEnabled_Duration) 314 { 315 $fStopped = MyHelpers::getmicrotime(); 316 $fDuration = $fStopped - $this->m_fStarted; 317 if (self::$m_bBlameCaller) 318 { 319 self::$m_aStats[$sOperation][$sArguments][] = array( 320 'time' => $fDuration, 321 'callers' => MyHelpers::get_callstack(1), 322 ); 323 } 324 else 325 { 326 self::$m_aStats[$sOperation][$sArguments][] = array( 327 'time' => $fDuration 328 ); 329 } 330 } 331 } 332 333 protected function ResetCounters() 334 { 335 if (self::$m_bEnabled_Duration) 336 { 337 $this->m_fStarted = MyHelpers::getmicrotime(); 338 } 339 340 if (self::$m_bEnabled_Memory) 341 { 342 $this->m_iInitialMemory = self::memory_get_usage(); 343 } 344 } 345 346 const HtmlReportFile = 'log/kpi.html'; 347 348 static protected function Report($sText) 349 { 350 file_put_contents(APPROOT.self::HtmlReportFile, "$sText\n", FILE_APPEND | LOCK_EX); 351 } 352 353 static protected function MemStr($iMemory) 354 { 355 return round($iMemory / 1024).' Kb'; 356 } 357 358 static protected function memory_get_usage() 359 { 360 if (function_exists('memory_get_usage')) 361 { 362 return memory_get_usage(true); 363 } 364 365 // Copied from the PHP manual 366 // 367 //If its Windows 368 //Tested on Win XP Pro SP2. Should work on Win 2003 Server too 369 //Doesn't work for 2000 370 //If you need it to work for 2000 look at http://us2.php.net/manual/en/function.memory-get-usage.php#54642 371 if (substr(PHP_OS,0,3) == 'WIN') 372 { 373 $output = array(); 374 exec('tasklist /FI "PID eq ' . getmypid() . '" /FO LIST', $output); 375 376 return preg_replace( '/[\D]/', '', $output[5] ) * 1024; 377 } 378 else 379 { 380 //We now assume the OS is UNIX 381 //Tested on Mac OS X 10.4.6 and Linux Red Hat Enterprise 4 382 //This should work on most UNIX systems 383 $pid = getmypid(); 384 exec("ps -eo%mem,rss,pid | grep $pid", $output); 385 $output = explode(" ", $output[0]); 386 //rss is given in 1024 byte units 387 return $output[1] * 1024; 388 } 389 } 390 391 static public function memory_get_peak_usage($bRealUsage = false) 392 { 393 if (function_exists('memory_get_peak_usage')) 394 { 395 return memory_get_peak_usage($bRealUsage); 396 } 397 // PHP > 5.2.1 - this verb depends on a compilation option 398 return 0; 399 } 400} 401 402