|
1
|
|
|
<?php |
|
2
|
|
|
/********************************************************************************\ |
|
3
|
|
|
* Copyright (C) Carl Taylor ([email protected]) * |
|
4
|
|
|
* Copyright (C) Torben Nehmer ([email protected]) for Code Cleanup * |
|
5
|
|
|
* Licensed under the BSD license upon request * |
|
6
|
|
|
\********************************************************************************/ |
|
7
|
|
|
|
|
8
|
|
|
/// Enable multiple timers to aid profiling of performance over sections of code |
|
9
|
|
|
|
|
10
|
|
|
/** |
|
11
|
|
|
* Execution time profiler. |
|
12
|
|
|
* |
|
13
|
|
|
* @deprecated 4.0 The Profiler class is deprecated, use third party tools like XHProf instead |
|
14
|
|
|
* |
|
15
|
|
|
* @package framework |
|
16
|
|
|
* @subpackage misc |
|
17
|
|
|
*/ |
|
18
|
|
|
class Profiler { |
|
19
|
|
|
var $description; |
|
|
|
|
|
|
20
|
|
|
var $startTime; |
|
|
|
|
|
|
21
|
|
|
var $endTime; |
|
|
|
|
|
|
22
|
|
|
var $initTime; |
|
|
|
|
|
|
23
|
|
|
var $cur_timer; |
|
|
|
|
|
|
24
|
|
|
var $stack; |
|
|
|
|
|
|
25
|
|
|
var $trail; |
|
|
|
|
|
|
26
|
|
|
var $trace; |
|
|
|
|
|
|
27
|
|
|
var $count; |
|
|
|
|
|
|
28
|
|
|
var $running; |
|
|
|
|
|
|
29
|
|
|
|
|
30
|
|
|
protected static $inst; |
|
31
|
|
|
|
|
32
|
|
|
/** |
|
33
|
|
|
* Initialise the timer. with the current micro time |
|
34
|
|
|
*/ |
|
35
|
|
|
public function Profiler( $output_enabled=false, $trace_enabled=false) |
|
|
|
|
|
|
36
|
|
|
{ |
|
37
|
|
|
$this->description = array(); |
|
38
|
|
|
$this->startTime = array(); |
|
39
|
|
|
$this->endTime = array(); |
|
40
|
|
|
$this->initTime = 0; |
|
41
|
|
|
$this->cur_timer = ""; |
|
42
|
|
|
$this->stack = array(); |
|
43
|
|
|
$this->trail = ""; |
|
44
|
|
|
$this->trace = ""; |
|
45
|
|
|
$this->count = array(); |
|
46
|
|
|
$this->running = array(); |
|
47
|
|
|
$this->initTime = $this->getMicroTime(); |
|
48
|
|
|
$this->output_enabled = $output_enabled; |
|
|
|
|
|
|
49
|
|
|
$this->trace_enabled = $trace_enabled; |
|
|
|
|
|
|
50
|
|
|
$this->startTimer('unprofiled'); |
|
51
|
|
|
} |
|
52
|
|
|
|
|
53
|
|
|
// Public Methods |
|
54
|
|
|
|
|
55
|
|
|
public static function init() { |
|
56
|
|
|
Deprecation::notice('4.0', 'The Profiler class is deprecated, use third party tools like XHProf instead'); |
|
57
|
|
|
if(!self::$inst) self::$inst = new Profiler(true,true); |
|
|
|
|
|
|
58
|
|
|
} |
|
59
|
|
|
|
|
60
|
|
|
public static function mark($name, $level2 = "", $desc = "") { |
|
|
|
|
|
|
61
|
|
|
if($level2 && $_GET['debug_profile'] > 1) $name .= " $level2"; |
|
62
|
|
|
|
|
63
|
|
|
if(!self::$inst) self::$inst = new Profiler(true,true); |
|
|
|
|
|
|
64
|
|
|
|
|
65
|
|
|
self::$inst->startTimer($name, $desc); |
|
66
|
|
|
} |
|
67
|
|
|
public static function unmark($name, $level2 = "", $desc = "") { |
|
|
|
|
|
|
68
|
|
|
if($level2 && $_GET['debug_profile'] > 1) $name .= " $level2"; |
|
69
|
|
|
|
|
70
|
|
|
if(!self::$inst) self::$inst = new Profiler(true,true); |
|
|
|
|
|
|
71
|
|
|
|
|
72
|
|
|
self::$inst->stopTimer($name, $desc); |
|
|
|
|
|
|
73
|
|
|
} |
|
74
|
|
|
public static function show($showTrace = false) { |
|
75
|
|
|
if(!self::$inst) self::$inst = new Profiler(true,true); |
|
|
|
|
|
|
76
|
|
|
|
|
77
|
|
|
echo "<div style=\"position: absolute; z-index: 100000; top: 20px; left: 20px; background-color: white;" |
|
78
|
|
|
. " padding: 20px; border: 1px #AAA solid; height: 80%; overflow: auto;\">"; |
|
79
|
|
|
echo "<p><a href=\"#\" onclick=\"this.parentNode.parentNode.style.display = 'none'; return false;\">" |
|
80
|
|
|
. "(Click to close)</a></p>"; |
|
81
|
|
|
self::$inst->printTimers(); |
|
82
|
|
|
if($showTrace) self::$inst->printTrace(); |
|
83
|
|
|
echo "</div>"; |
|
84
|
|
|
} |
|
85
|
|
|
|
|
86
|
|
|
/** |
|
87
|
|
|
* Start an individual timer |
|
88
|
|
|
* This will pause the running timer and place it on a stack. |
|
89
|
|
|
* @param string $name name of the timer |
|
90
|
|
|
* @param string optional $desc description of the timer |
|
91
|
|
|
*/ |
|
92
|
|
|
public function startTimer($name, $desc="" ){ |
|
93
|
|
|
$this->trace.="start $name\n"; |
|
94
|
|
|
$n=array_push( $this->stack, $this->cur_timer ); |
|
95
|
|
|
$this->__suspendTimer( $this->stack[$n-1] ); |
|
96
|
|
|
$this->startTime[$name] = $this->getMicroTime(); |
|
97
|
|
|
$this->cur_timer=$name; |
|
98
|
|
|
$this->description[$name] = $desc; |
|
99
|
|
|
if (!array_key_exists($name,$this->count)) |
|
100
|
|
|
$this->count[$name] = 1; |
|
101
|
|
|
else |
|
102
|
|
|
$this->count[$name]++; |
|
103
|
|
|
} |
|
104
|
|
|
|
|
105
|
|
|
/** |
|
106
|
|
|
* Stop an individual timer |
|
107
|
|
|
* Restart the timer that was running before this one |
|
108
|
|
|
* @param string $name name of the timer |
|
109
|
|
|
*/ |
|
110
|
|
|
public function stopTimer($name){ |
|
111
|
|
|
$this->trace.="stop $name\n"; |
|
112
|
|
|
$this->endTime[$name] = $this->getMicroTime(); |
|
113
|
|
|
if (!array_key_exists($name, $this->running)) |
|
114
|
|
|
$this->running[$name] = $this->elapsedTime($name); |
|
115
|
|
|
else |
|
116
|
|
|
$this->running[$name] += $this->elapsedTime($name); |
|
117
|
|
|
$this->cur_timer=array_pop($this->stack); |
|
118
|
|
|
$this->__resumeTimer($this->cur_timer); |
|
119
|
|
|
} |
|
120
|
|
|
|
|
121
|
|
|
/** |
|
122
|
|
|
* measure the elapsed time of a timer without stoping the timer if |
|
123
|
|
|
* it is still running |
|
124
|
|
|
*/ |
|
125
|
|
|
public function elapsedTime($name){ |
|
126
|
|
|
// This shouldn't happen, but it does once. |
|
127
|
|
|
if (!array_key_exists($name,$this->startTime)) |
|
128
|
|
|
return 0; |
|
129
|
|
|
|
|
130
|
|
|
if(array_key_exists($name,$this->endTime)){ |
|
131
|
|
|
return ($this->endTime[$name] - $this->startTime[$name]); |
|
132
|
|
|
} else { |
|
133
|
|
|
$now=$this->getMicroTime(); |
|
134
|
|
|
return ($now - $this->startTime[$name]); |
|
135
|
|
|
} |
|
136
|
|
|
}//end start_time |
|
137
|
|
|
|
|
138
|
|
|
/** |
|
139
|
|
|
* Measure the elapsed time since the profile class was initialised |
|
140
|
|
|
* |
|
141
|
|
|
*/ |
|
142
|
|
|
public function elapsedOverall(){ |
|
143
|
|
|
$oaTime = $this->getMicroTime() - $this->initTime; |
|
144
|
|
|
return($oaTime); |
|
145
|
|
|
}//end start_time |
|
146
|
|
|
|
|
147
|
|
|
/** |
|
148
|
|
|
* print out a log of all the timers that were registered |
|
149
|
|
|
* |
|
150
|
|
|
*/ |
|
151
|
|
|
public function printTimers($enabled=false) |
|
152
|
|
|
{ |
|
153
|
|
|
if($this->output_enabled||$enabled){ |
|
154
|
|
|
$TimedTotal = 0; |
|
155
|
|
|
$tot_perc = 0; |
|
156
|
|
|
ksort($this->description); |
|
157
|
|
|
print("<pre>\n"); |
|
158
|
|
|
$oaTime = $this->getMicroTime() - $this->initTime; |
|
159
|
|
|
echo"============================================================================\n"; |
|
160
|
|
|
echo " PROFILER OUTPUT\n"; |
|
161
|
|
|
echo"============================================================================\n"; |
|
162
|
|
|
print( "Calls Time Routine\n"); |
|
163
|
|
|
echo"-----------------------------------------------------------------------------\n"; |
|
164
|
|
|
while (list ($key, $val) = each ($this->description)) { |
|
|
|
|
|
|
165
|
|
|
$t = $this->elapsedTime($key); |
|
166
|
|
|
$total = $this->running[$key]; |
|
167
|
|
|
$count = $this->count[$key]; |
|
168
|
|
|
$TimedTotal += $total; |
|
169
|
|
|
$perc = ($total/$oaTime)*100; |
|
170
|
|
|
$tot_perc+=$perc; |
|
171
|
|
|
// $perc=sprintf("%3.2f", $perc ); |
|
|
|
|
|
|
172
|
|
|
$lines[ sprintf( "%3d %3.4f ms (%3.2f %%) %s\n", $count, $total*1000, $perc, $key) ] = $total; |
|
|
|
|
|
|
173
|
|
|
} |
|
174
|
|
|
arsort($lines); |
|
175
|
|
|
foreach($lines as $line => $total) { |
|
176
|
|
|
echo $line; |
|
177
|
|
|
} |
|
178
|
|
|
|
|
179
|
|
|
echo "\n"; |
|
180
|
|
|
|
|
181
|
|
|
$missed=$oaTime-$TimedTotal; |
|
182
|
|
|
$perc = ($missed/$oaTime)*100; |
|
183
|
|
|
$tot_perc+=$perc; |
|
184
|
|
|
// $perc=sprintf("%3.2f", $perc ); |
|
|
|
|
|
|
185
|
|
|
printf( " %3.4f ms (%3.2f %%) %s\n", $missed*1000,$perc, "Missed"); |
|
186
|
|
|
|
|
187
|
|
|
echo"============================================================================\n"; |
|
188
|
|
|
|
|
189
|
|
|
printf( " %3.4f ms (%3.2f %%) %s\n", $oaTime*1000,$tot_perc, "OVERALL TIME"); |
|
190
|
|
|
|
|
191
|
|
|
echo"============================================================================\n"; |
|
192
|
|
|
|
|
193
|
|
|
print("</pre>"); |
|
194
|
|
|
} |
|
195
|
|
|
} |
|
196
|
|
|
|
|
197
|
|
|
public function printTrace( $enabled=false ) |
|
198
|
|
|
{ |
|
199
|
|
|
if($this->trace_enabled||$enabled){ |
|
200
|
|
|
print("<pre>"); |
|
201
|
|
|
print("Trace\n$this->trace\n\n"); |
|
202
|
|
|
print("</pre>"); |
|
203
|
|
|
} |
|
204
|
|
|
} |
|
205
|
|
|
|
|
206
|
|
|
/// Internal Use Only Functions |
|
207
|
|
|
|
|
208
|
|
|
/** |
|
209
|
|
|
* Get the current time as accuratly as possible |
|
210
|
|
|
* |
|
211
|
|
|
*/ |
|
212
|
|
|
public function getMicroTime(){ |
|
213
|
|
|
$tmp=explode(' ', microtime()); |
|
214
|
|
|
$rt=$tmp[0]+$tmp[1]; |
|
215
|
|
|
return $rt; |
|
216
|
|
|
} |
|
217
|
|
|
|
|
218
|
|
|
/** |
|
219
|
|
|
* resume an individual timer |
|
220
|
|
|
* |
|
221
|
|
|
*/ |
|
222
|
|
|
public function __resumeTimer($name){ |
|
223
|
|
|
$this->trace.="resume $name\n"; |
|
224
|
|
|
$this->startTime[$name] = $this->getMicroTime(); |
|
225
|
|
|
} |
|
226
|
|
|
|
|
227
|
|
|
/** |
|
228
|
|
|
* suspend an individual timer |
|
229
|
|
|
* |
|
230
|
|
|
*/ |
|
231
|
|
|
public function __suspendTimer($name){ |
|
232
|
|
|
$this->trace.="suspend $name\n"; |
|
233
|
|
|
$this->endTime[$name] = $this->getMicroTime(); |
|
234
|
|
|
if (!array_key_exists($name, $this->running)) |
|
235
|
|
|
$this->running[$name] = $this->elapsedTime($name); |
|
236
|
|
|
else |
|
237
|
|
|
$this->running[$name] += $this->elapsedTime($name); |
|
238
|
|
|
} |
|
239
|
|
|
} |
|
240
|
|
|
|
The PSR-2 coding standard requires that all properties in a class have their visibility explicitly declared. If you declare a property using
the property is implicitly global.
To learn more about the PSR-2, please see the PHP-FIG site on the PSR-2.