Revert removal of CPU time profiling in 29658-29661. Those 0's and 10's will add...
authorTim Starling <tstarling@users.mediawiki.org>
Sat, 26 Jan 2008 01:49:17 +0000 (01:49 +0000)
committerTim Starling <tstarling@users.mediawiki.org>
Sat, 26 Jan 2008 01:49:17 +0000 (01:49 +0000)
includes/ProfilerSimple.php
includes/ProfilerSimpleUDP.php

index 07cc149..20ab99c 100644 (file)
@@ -12,18 +12,22 @@ class ProfilerSimple extends Profiler {
        var $mProfileID = false;
 
        function __construct() {
-               global $wgRequestTime;
-               if (!empty($wgRequestTime)) {
-                       $this->mWorkStack[] = array( '-total', 0, $wgRequestTime);
+               global $wgRequestTime,$wgRUstart;
+               if (!empty($wgRequestTime) && !empty($wgRUstart)) {
+                       $this->mWorkStack[] = array( '-total', 0, $wgRequestTime,$this->getCpuTime($wgRUstart));
 
+                       $elapsedcpu = $this->getCpuTime() - $this->getCpuTime($wgRUstart);
                        $elapsedreal = microtime(true) - $wgRequestTime;
 
                        $entry =& $this->mCollated["-setup"];
                        if (!is_array($entry)) {
-                               $entry = array('real' => 0.0, 'count' => 0);
+                               $entry = array('cpu'=> 0.0, 'cpu_sq' => 0.0, 'real' => 0.0, 'real_sq' => 0.0, 'count' => 0);
                                $this->mCollated["-setup"] =& $entry;
                        }
+                       $entry['cpu'] += $elapsedcpu;
+                       $entry['cpu_sq'] += $elapsedcpu*$elapsedcpu;
                        $entry['real'] += $elapsedreal;
+                       $entry['real_sq'] += $elapsedreal*$elapsedreal;
                        $entry['count']++;
                }
        }
@@ -49,7 +53,7 @@ class ProfilerSimple extends Profiler {
                if ($wgDebugFunctionEntry) {
                        $this->debug(str_repeat(' ', count($this->mWorkStack)).'Entering '.$functionname."\n");
                }
-               $this->mWorkStack[] = array($functionname, count( $this->mWorkStack),microtime(true));
+               $this->mWorkStack[] = array($functionname, count( $this->mWorkStack ), microtime(true), $this->getCpuTime());
        }
 
        function profileOut($functionname) {
@@ -59,7 +63,7 @@ class ProfilerSimple extends Profiler {
                        $this->debug(str_repeat(' ', count($this->mWorkStack) - 1).'Exiting '.$functionname."\n");
                }
 
-               list($ofname, /* $ocount */ ,$ortime) = array_pop($this->mWorkStack);
+               list($ofname, /* $ocount */ ,$ortime,$octime) = array_pop($this->mWorkStack);
 
                if (!$ofname) {
                        $this->debug("Profiling error: $functionname\n");
@@ -78,12 +82,16 @@ class ProfilerSimple extends Profiler {
                                        'real' => 0.0, 'count' => 1);
                        }
                        $entry =& $this->mCollated[$functionname];
+                       $elapsedcpu = $this->getCpuTime() - $octime;
                        $elapsedreal = microtime(true) - $ortime;
                        if (!is_array($entry)) {
-                               $entry = array('real' => 0.0, 'count' => 0);
+                               $entry = array('cpu'=> 0.0, 'cpu_sq' => 0.0, 'real' => 0.0, 'real_sq' => 0.0, 'count' => 0);
                                $this->mCollated[$functionname] =& $entry;
                        }
+                       $entry['cpu'] += $elapsedcpu;
+                       $entry['cpu_sq'] += $elapsedcpu*$elapsedcpu;
                        $entry['real'] += $elapsedreal;
+                       $entry['real_sq'] += $elapsedreal*$elapsedreal;
                        $entry['count']++;
 
                }
@@ -93,6 +101,17 @@ class ProfilerSimple extends Profiler {
                /* Implement in output subclasses */
        }
 
+       function getCpuTime($ru=null) {
+               if ( function_exists( 'getrusage' ) ) {
+                       if ( $ru == null )
+                               $ru = getrusage();
+                       return ($ru['ru_utime.tv_sec'] + $ru['ru_stime.tv_sec'] + ($ru['ru_utime.tv_usec'] + 
+                               $ru['ru_stime.tv_usec']) * 1e-6);
+               } else {
+                       return 0;
+               }
+       }
+
        /* If argument is passed, it assumes that it is dual-format time string, returns proper float time value */
        function getTime($time=null) {
                if ($time==null)
index 7fcd9ba..7d2f7e2 100644 (file)
@@ -22,8 +22,8 @@ class ProfilerSimpleUDP extends ProfilerSimple {
                $plength=0;
                $packet="";
                foreach ($this->mCollated as $entry=>$pfdata) {
-                       $pfline=sprintf ("%s %s %d 0 0 %f 0 %s\n", $this->getProfileID(),"-",$pfdata['count'],
-                               $pfdata['real'],$entry);
+                       $pfline=sprintf ("%s %s %d %f %f %f %f %s\n", $this->getProfileID(),"-",$pfdata['count'],
+                               $pfdata['cpu'],$pfdata['cpu_sq'],$pfdata['real'],$pfdata['real_sq'],$entry);
                        $length=strlen($pfline);
                        /* printf("<!-- $pfline -->"); */
                        if ($length+$plength>1400) {
@@ -37,3 +37,4 @@ class ProfilerSimpleUDP extends ProfilerSimple {
                socket_sendto($sock,$packet,$plength,0x100,$wgUDPProfilerHost,$wgUDPProfilerPort);
        }
 }
+