]> git.mjollnir.org Git - moodle.git/commitdiff
Started adding enhanced profiling using APD.
authornicolasconnault <nicolasconnault>
Tue, 20 Mar 2007 00:34:05 +0000 (00:34 +0000)
committernicolasconnault <nicolasconnault>
Tue, 20 Mar 2007 00:34:05 +0000 (00:34 +0000)
lib/profilerlib.php [new file with mode: 0755]
lib/setuplib.php

diff --git a/lib/profilerlib.php b/lib/profilerlib.php
new file mode 100755 (executable)
index 0000000..6e8f261
--- /dev/null
@@ -0,0 +1,375 @@
+<?php
+/**
+* Profiler adapted from Pear::APD's pprofp script. Not quite there yet, I need
+* to get this to accept a similar list of arguments as the script does,
+* and process them the same way. Also make sure that the file being loaded
+* is the right one. Also support multiple pids used in one page load (up to 4 so far).
+* Then output all this in a nicely formatted table.
+*/
+class Profiler
+{
+    var $stimes;
+    var $utimes;
+    var $calls;
+    var $c_stimes;
+    var $c_utimes;
+    var $mem;
+
+    function get_profiling($opt = array())
+    { 
+        global $CFG;
+echo "BLAH";
+        $retstring = '';
+        $dataFile = ini_get('apd.dumpdir') . '/pprof.' . getmypid() . '.*';
+        
+        if (!$dataFile) {
+            return $this->usage();
+        }
+        
+        if(($DATA = fopen($dataFile, "r")) == FALSE) {
+            die("Failed to open $dataFile for reading\n");
+        }
+
+        $cfg = array();
+        $this->parse_info('HEADER', $DATA, $cfg);
+
+        $callstack = array();
+        $calls = array();
+        $indent_cur = 0;
+        $file_hash = array();
+        $this->mem = array();
+        $t_rtime = 0;
+        $t_stime = 0;
+        $t_utime = 0;
+        $c_rtimes = array();
+        $this->c_stimes = array();
+        $this->c_utimes = array();
+        $rtimes = array();
+        $this->stimes = array();
+        $this->utimes = array();
+        $rtotal = 0;
+        $stotal = 0;
+        $utotal = 0;
+        $last_memory = 0;
+
+        $symbol_hash = array();
+        $symbol_type = array();
+
+        while($line = fgets($DATA)) {
+            $line = rtrim($line);
+            if(preg_match("/^END_TRACE/", $line)){
+                break;
+            }
+            list($token, $data) = preg_split("/ /",$line, 2);
+            if($token == '!') {
+            list ($index, $file) = preg_split("/ /", $data, 2);
+            $file_hash[$index] = $file;
+            continue;
+            }
+            if( $token == '&') {
+                list ($index, $name, $type) = preg_split("/ /", $data, 3);
+                $symbol_hash[$index] = $name;
+            $symbol_type[$index] = $type;
+                continue;
+            }
+            if( $token == '+') {
+                list($index, $file, $line) = preg_split("/ /",$data, 3);
+                if(array_key_exists('i',$opt) && $symbol_type[$index] == 1) {
+                    continue;
+                }      
+                $index_cur = $index;
+                $calls[$index_cur]++;
+                array_push($callstack, $index_cur);
+                if(array_key_exists('T', $opt)) {
+                    if(array_key_exists('c', $opt)) {
+                       $retstring .= sprintf("%2.02f ", $rtotal/1000000);
+                    }
+                    $retstring .= str_repeat("  ", $indent_cur).$symbol_hash[$index_cur]."\n";
+                if(array_key_exists('m', $opt)) {
+                $retstring .= str_repeat("  ", $indent_cur)."C: $file_hash[$file]:$line M: $memory\n";
+                }
+            }
+                elseif(array_key_exists('t', $opt)) {
+                    if ( $indent_last == $indent_cur && $index_last == $index_cur ) {
+                        $repcnt++;
+                    }
+                    else {
+                        if ( $repcnt ) {
+                            $repstr = ' ('.++$repcnt.'x)';
+                        }
+                        if(array_key_exists('c', $opt)) {
+                            $retstring .= sprintf("%2.02f ", $rtotal/1000000);
+                        }
+                        $retstring .= str_repeat("  ", $indent_last).$symbol_hash[$index_last].$repstr."\n";
+                if(array_key_exists('m', $opt)) {
+                   $retstring .= str_repeat("  ", $indent_cur)."C: $file_hash[$file_last]:$line_last M: $memory\n";
+                }
+                        $repstr = '';
+                        $repcnt = 0;
+                        $index_last = $index_cur;
+                        $indent_last = $indent_cur;
+                $file_last = $file;
+                $line_last = $line;
+                    }
+                }
+            $indent_cur++;
+                continue;
+            }
+            if( $token == '@') {
+                list($file_no, $line_no, $ut, $st, $rt) = preg_split("/ /", $data);
+                $top = array_pop($callstack);
+                $this->utimes[$top] += $ut;
+                $utotal += $ut;
+                $this->stimes[$top] += $st;
+                $stotal += $st;
+                $rtimes[$top] += $rt;
+                $rtotal += $rt;
+                array_push($callstack, $top);
+            foreach ($callstack as $stack_element) {
+                    $this->c_utimes[$stack_element] += $ut;
+                    $this->c_stimes[$stack_element] += $st;
+                    $c_rtimes[$stack_element] += $rt;
+                }
+                continue;
+            }
+            if ($token == '-') {
+                list  ($index, $memory) = preg_split("/ /", $data, 2);
+                if(array_key_exists('i',$opt) && $symbol_type[$index] == 1)
+                {
+                    continue;
+                }
+                $this->mem[$index] += ($memory - $last_memory);
+                $last_memory = $memory;
+                $indent_cur--;
+                $tmp = array_pop($callstack);
+                continue;
+            }
+        }
+        $this->parse_info('FOOTER', $DATA, $cfg);
+        $sort = 'by_time';
+        if(array_key_exists('l', $opt)) { $sort = 'by_calls'; }
+        if(array_key_exists('m', $opt)) { $sort = 'by_mem'; }
+        if(array_key_exists('a', $opt)) { $sort = 'by_name'; }
+        if(array_key_exists('v', $opt)) { $sort = 'by_avgcpu'; }
+        if(array_key_exists('r', $opt)) { $sort = 'by_rtime'; }
+        if(array_key_exists('R', $opt)) { $sort = 'by_c_rtime'; }
+        if(array_key_exists('s', $opt)) { $sort = 'by_stime'; }
+        if(array_key_exists('S', $opt)) { $sort = 'by_c_stime'; }
+        if(array_key_exists('u', $opt)) { $sort = 'by_utime'; }
+        if(array_key_exists('U', $opt)) { $sort = 'by_c_utime'; }
+        if(array_key_exists('Z', $opt)) { $sort = 'by_c_time'; }
+        if( !count($symbol_hash)) {
+            continue;
+        }
+
+        $retstring .= sprintf("
+        Trace for %s
+        Total Elapsed Time = %4.2f
+        Total System Time  = %4.2f
+        Total User Time    = %4.2f
+        ", $cfg['caller'], $rtotal/1000000, $stotal/1000000, $utotal/1000000);
+        
+        $retstring .= "\n
+                 Real         User        System             secs/    cumm
+        %Time (excl/cumm)  (excl/cumm)  (excl/cumm) Calls    call    s/call  Memory Usage Name
+        --------------------------------------------------------------------------------------\n";
+        $l = 0;
+        $itotal = 0;
+        $percall = 0;
+        $cpercall = 0;
+
+        uksort($symbol_hash, $sort);
+        foreach (array_keys($symbol_hash) as $j) {
+            if(array_key_exists('i', $opt) && $symbol_type[$j] == 1) {
+                continue;
+            }
+            if ($l++ <  $opt['O']) {
+                $pcnt = 100*($this->stimes[$j] + $this->utimes[$j])/($utotal + $stotal + $itotal);
+                $c_pcnt = 100* ($this->c_stimes[$j] + $this->c_utimes[$j])/($utotal + $stotal + $itotal);
+                $rsecs = $rtimes[$j]/1000000;
+                $ssecs = $this->stimes[$j]/1000000;
+                $usecs = $this->utimes[$j]/1000000;
+                $c_rsecs = $c_rtimes[$j]/1000000;
+                $c_ssecs = $this->c_stimes[$j]/1000000;
+                $c_usecs = $this->c_utimes[$j]/1000000;
+                $ncalls = $calls[$j];
+            if(array_key_exists('z', $opt)) {
+                    $percall = ($usecs + $ssecs)/$ncalls;
+                    $cpercall = ($c_usecs + $c_ssecs)/$ncalls;
+                        if($utotal + $stotal) {
+                    $pcnt = 100*($this->stimes[$j] + $this->utimes[$j])/($utotal + $stotal);
+                        }
+                        else {
+                            $pcnt = 100;
+                        }
+            }
+            if(array_key_exists('Z', $opt)) {
+                    $percall = ($usecs + $ssecs)/$ncalls;
+                    $cpercall = ($c_usecs + $c_ssecs)/$ncalls;
+                        if($utotal + $stotal) {
+                    $pcnt = 100*($this->c_stimes[$j] + $this->c_utimes[$j])/($utotal + $stotal);
+                        }
+                        else {
+                            $pcnt = 100;
+                        }
+            }
+            if(array_key_exists('r', $opt)) {
+                    $percall = ($rsecs)/$ncalls;
+                    $cpercall = ($c_rsecs)/$ncalls;
+                        if($rtotal) {
+                    $pcnt = 100*$rtimes[$j]/$rtotal;
+                        }
+                        else {
+                            $pcnt = 100;
+                        }
+            }
+            if(array_key_exists('R', $opt)) {
+                    $percall = ($rsecs)/$ncalls;
+                    $cpercall = ($c_rsecs)/$ncalls;
+                        if($rtotal) {
+                    $pcnt = 100*$c_rtimes[$j]/$rtotal;
+                        }
+                        else {
+                            $pcnt = 100;
+                        }
+            }
+            if(array_key_exists('u', $opt)) {
+                    $percall = ($usecs)/$ncalls;
+                    $cpercall = ($c_usecs)/$ncalls;
+                        if($utotal) {
+                    $pcnt = 100*$this->utimes[$j]/$utotal;
+                        } 
+                        else {
+                            $pcnt = 100;
+                        }
+            }
+            if(array_key_exists('U', $opt)) {
+                    $percall = ($usecs)/$ncalls;
+                    $cpercall = ($c_usecs)/$ncalls;
+                        if($utotal) {
+                    $pcnt = 100*$this->c_utimes[$j]/$utotal;
+                        }
+                        else {
+                            $pcnt = 100;
+                        }
+            }
+            if(array_key_exists('s', $opt)) {
+                    $percall = ($ssecs)/$ncalls;
+                    $cpercall = ($c_ssecs)/$ncalls;
+                        if($stotal) {
+                    $pcnt = 100*$this->stimes[$j]/$stotal;
+                        }
+                        else {
+                            $pcnt = 100;
+                        }
+            }
+            if(array_key_exists('S', $opt)) {
+                    $percall = ($ssecs)/$ncalls;
+                    $cpercall = ($c_ssecs)/$ncalls;
+                        if($stotal) {
+                    $pcnt = 100*$this->c_stimes[$j]/$stotal;
+                        }
+                        else {
+                            $pcnt = 100;
+                        }
+            }
+        //        $cpercall = ($c_usecs + $c_ssecs)/$ncalls;
+                $mem_usage = $this->mem[$j];
+                $name = $symbol_hash[$j];
+                $retstring .=  sprintf("%3.01f %2.02f %2.02f  %2.02f %2.02f  %2.02f %2.02f  %4d  %2.04f   %2.04f %12d %s\n", 
+                                $pcnt, $rsecs, $c_rsecs, $usecs, $c_usecs, $ssecs, $c_ssecs, $ncalls, $percall, $cpercall, $mem_usage, $name);
+                return $retstring;
+            }
+        }
+    }
+
+    function usage() {
+    return <<<EOD
+    pprofp <flags> <trace file>
+        Sort options
+        -a          Sort by alphabetic names of subroutines.
+        -l          Sort by number of calls to subroutines
+        -m          Sort by memory used in a function call.
+        -r          Sort by real time spent in subroutines.
+        -R          Sort by real time spent in subroutines (inclusive of child calls).
+        -s          Sort by system time spent in subroutines.
+        -S          Sort by system time spent in subroutines (inclusive of child calls).
+        -u          Sort by user time spent in subroutines.
+        -U          Sort by user time spent in subroutines (inclusive of child calls).
+        -v          Sort by average amount of time spent in subroutines.
+        -z          Sort by user+system time spent in subroutines. (default)
+
+        Display options
+        -c          Display Real time elapsed alongside call tree.
+        -i          Suppress reporting for php builtin functions
+        -O <cnt>    Specifies maximum number of subroutines to display. (default 15)
+        -t          Display compressed call tree.
+        -T          Display uncompressed call tree.
+
+EOD;
+        exit(1);
+    }
+
+    function parse_info($tag, $datasource, &$cfg) {
+        while($line = fgets($datasource)) {
+            $line = rtrim($line);
+            if(preg_match("/^END_$tag$/", $line)) {
+                break;
+            }
+            if(preg_match("/(\w+)=(.*)/", $line, $matches)) {
+                $cfg[$matches[1]] = $matches[2];
+            }
+        }
+    }
+
+    function num_cmp($a, $b) {
+        if (intval($a) > intval($b)) { return 1;}
+        elseif(intval($a) < intval($b)) { return -1;}
+        else {return 0;}
+    }
+
+    function by_time($a,$b) {
+        return $this->num_cmp(($this->stimes[$b] + $this->utimes[$b]),($this->stimes[$a] + $this->utimes[$a]));
+    }
+
+    function by_c_time($a,$b) {
+        return $this->num_cmp(($this->c_stimes[$b] + $this->c_utimes[$b]),($this->c_stimes[$a] + $this->c_utimes[$a]));
+    }
+
+    function by_avgcpu($a,$b) {
+        return $this->num_cmp(($this->stimes[$b] + $this->utimes[$b])/$this->calls[$b],($this->stimes[$a] + $this->utimes[$a])/$this->calls[$a]);
+    }
+
+    function by_calls($a, $b) {
+        return $this->num_cmp($this->calls[$b], $this->calls[$a]);
+    }
+    
+    function by_rtime($a,$b) { 
+        return $this->num_cmp($this->rtimes[$b], $this->rtimes[$a]);
+    }
+    
+    function by_c_rtime($a,$b) { 
+        return $this->num_cmp($this->c_rtimes[$b], $this->c_rtimes[$a]); 
+    }
+    
+    function by_stime($a,$b) { 
+        return $this->num_cmp($this->stimes[$b], $this->stimes[$a]); 
+    }
+    
+    function by_c_stime($a,$b) { 
+        return $this->num_cmp($this->c_stimes[$b], $this->c_stimes[$a]); 
+    }
+    
+    function by_utime($a,$b) { 
+        return $this->num_cmp($this->utimes[$b], $this->utimes[$a]); 
+    }
+    
+    function by_c_utime($a,$b) { 
+        return $this->num_cmp($this->c_utimes[$b], $this->c_utimes[$a]); 
+    }
+    
+    function by_mem($a, $b) { 
+        return $this->num_cmp($this->mem[$b], $this->mem[$a]); 
+    } 
+}
+?>
index d564d0d3404a85126dced6ad4443ec0f872167c6..723e063bcca2d081e18a179a7d3dd9ae4d518cf1 100644 (file)
@@ -16,7 +16,7 @@
 function init_performance_info() {
 
     global $PERF;
-
+  
     $PERF = new Object;
     $PERF->dbqueries = 0;   
     $PERF->logwrites = 0;
@@ -29,6 +29,11 @@ function init_performance_info() {
     if (function_exists('posix_times')) {
         $PERF->startposixtimes = posix_times();  
     }
+    if (function_exists('apd_set_pprof_trace')) {
+        // APD profiling
+        apd_set_pprof_trace();
+        $PERF->process = 44444;
+    }
 }
 
 /**