r74913 MediaWiki - Code Review archive

Repository:MediaWiki
Revision:r74912‎ | r74913 | r74914 >
Date:19:04, 17 October 2010
Author:reedy
Status:reverted (Comments)
Tags:
Comment:
Move profiler stuff to own folder, updater AutoLoader to match

ProfilerSimpleTrace isn't in AutoLoader. Neither is ProfilerStub

Profiler also says " * This file is only included if profiling is enabled"...
Modified paths:
  • /trunk/phase3/includes/AutoLoader.php (modified) (history)
  • /trunk/phase3/includes/Profiler.php (deleted) (history)
  • /trunk/phase3/includes/ProfilerSimple.php (deleted) (history)
  • /trunk/phase3/includes/ProfilerSimpleText.php (deleted) (history)
  • /trunk/phase3/includes/ProfilerSimpleTrace.php (deleted) (history)
  • /trunk/phase3/includes/ProfilerSimpleUDP.php (deleted) (history)
  • /trunk/phase3/includes/ProfilerStub.php (deleted) (history)
  • /trunk/phase3/includes/profiler (added) (history)
  • /trunk/phase3/includes/profiler/Profiler.php (added) (history)
  • /trunk/phase3/includes/profiler/ProfilerSimple.php (added) (history)
  • /trunk/phase3/includes/profiler/ProfilerSimpleText.php (added) (history)
  • /trunk/phase3/includes/profiler/ProfilerSimpleTrace.php (added) (history)
  • /trunk/phase3/includes/profiler/ProfilerSimpleUDP.php (added) (history)
  • /trunk/phase3/includes/profiler/ProfilerStub.php (added) (history)

Diff [purge]

Index: trunk/phase3/includes/ProfilerSimpleText.php
@@ -1,39 +0,0 @@
2 -<?php
3 -/**
4 - * @file
5 - * @ingroup Profiler
6 - */
7 -
8 -require_once( dirname( __FILE__ ) . '/ProfilerSimple.php' );
9 -
10 -/**
11 - * The least sophisticated profiler output class possible, view your source! :)
12 - *
13 - * Put the following 3 lines in StartProfiler.php:
14 - *
15 - * require_once( dirname( __FILE__ ) . '/includes/ProfilerSimpleText.php' );
16 - * $wgProfiler = new ProfilerSimpleText;
17 - * $wgProfiler->visible=true;
18 - *
19 - * @ingroup Profiler
20 - */
21 -class ProfilerSimpleText extends ProfilerSimple {
22 - public $visible=false; /* Show as <PRE> or <!-- ? */
23 - static private $out;
24 -
25 - function getFunctionReport() {
26 - if($this->mTemplated) {
27 - uasort($this->mCollated,array('self','sort'));
28 - array_walk($this->mCollated,array('self','format'));
29 - if ($this->visible) {
30 - print '<pre>'.self::$out.'</pre>';
31 - } else {
32 - print "<!--\n".self::$out."\n-->\n";
33 - }
34 - }
35 - }
36 -
37 - /* dense is good */
38 - static function sort($a,$b) { return $a['real']<$b['real']; /* sort descending by time elapsed */ }
39 - static function format($item,$key) { self::$out .= sprintf("%3.6f %6d - %s\n",$item['real'],$item['count'], $key); }
40 -}
Index: trunk/phase3/includes/ProfilerStub.php
@@ -1,52 +0,0 @@
2 -<?php
3 -/**
4 - * Stub profiling functions
5 - * @file
6 - * @ingroup Profiler
7 - */
8 -
9 -/** backward compatibility */
10 -$wgProfiling = false;
11 -$wgProfiler = null;
12 -
13 -/** is setproctitle function available ? */
14 -$haveProctitle = function_exists( 'setproctitle' );
15 -
16 -/**
17 - * Begin profiling of a function
18 - * @param $fn string
19 - */
20 -function wfProfileIn( $fn = '' ) {
21 - global $hackwhere, $wgDBname, $haveProctitle;
22 - if( $haveProctitle ){
23 - $hackwhere[] = $fn;
24 - setproctitle( $fn . " [$wgDBname]" );
25 - }
26 -}
27 -
28 -/**
29 - * Stop profiling of a function
30 - * @param $fn string
31 - */
32 -function wfProfileOut( $fn = '' ) {
33 - global $hackwhere, $wgDBname, $haveProctitle;
34 - if( !$haveProctitle ) {
35 - return;
36 - }
37 - if( count( $hackwhere ) ) {
38 - array_pop( $hackwhere );
39 - }
40 - if( count( $hackwhere ) ) {
41 - setproctitle( $hackwhere[count( $hackwhere )-1] . " [$wgDBname]" );
42 - }
43 -}
44 -
45 -/**
46 - * Does nothing, just for compatibility
47 - */
48 -function wfGetProfilingOutput( $s, $e ) {}
49 -
50 -/**
51 - * Does nothing, just for compatibility
52 - */
53 -function wfProfileClose() {}
Index: trunk/phase3/includes/Profiler.php
@@ -1,463 +0,0 @@
2 -<?php
3 -/**
4 - * @defgroup Profiler Profiler
5 - *
6 - * @file
7 - * @ingroup Profiler
8 - * This file is only included if profiling is enabled
9 - */
10 -
11 -/** backward compatibility */
12 -$wgProfiling = true;
13 -
14 -/**
15 - * Begin profiling of a function
16 - * @param $functionname String: name of the function we will profile
17 - */
18 -function wfProfileIn( $functionname ) {
19 - global $wgProfiler;
20 - $wgProfiler->profileIn( $functionname );
21 -}
22 -
23 -/**
24 - * Stop profiling of a function
25 - * @param $functionname String: name of the function we have profiled
26 - */
27 -function wfProfileOut( $functionname = 'missing' ) {
28 - global $wgProfiler;
29 - $wgProfiler->profileOut( $functionname );
30 -}
31 -
32 -/**
33 - * Returns a profiling output to be stored in debug file
34 - *
35 - * @param $start Float
36 - * @param $elapsed Float: time elapsed since the beginning of the request
37 - */
38 -function wfGetProfilingOutput( $start, $elapsed ) {
39 - global $wgProfiler;
40 - return $wgProfiler->getOutput( $start, $elapsed );
41 -}
42 -
43 -/**
44 - * Close opened profiling sections
45 - */
46 -function wfProfileClose() {
47 - global $wgProfiler;
48 - $wgProfiler->close();
49 -}
50 -
51 -if (!function_exists('memory_get_usage')) {
52 - # Old PHP or --enable-memory-limit not compiled in
53 - function memory_get_usage() {
54 - return 0;
55 - }
56 -}
57 -
58 -/**
59 - * @ingroup Profiler
60 - * @todo document
61 - */
62 -class Profiler {
63 - var $mStack = array (), $mWorkStack = array (), $mCollated = array ();
64 - var $mCalls = array (), $mTotals = array ();
65 - var $mTemplated = false;
66 -
67 - function __construct() {
68 - // Push an entry for the pre-profile setup time onto the stack
69 - global $wgRequestTime;
70 - if ( !empty( $wgRequestTime ) ) {
71 - $this->mWorkStack[] = array( '-total', 0, $wgRequestTime, 0 );
72 - $this->mStack[] = array( '-setup', 1, $wgRequestTime, 0, microtime(true), 0 );
73 - } else {
74 - $this->profileIn( '-total' );
75 - }
76 - }
77 -
78 - /**
79 - * Called by wfProfieIn()
80 - *
81 - * @param $functionname String
82 - */
83 - function profileIn( $functionname ) {
84 - global $wgDebugFunctionEntry, $wgProfiling;
85 - if( !$wgProfiling ) return;
86 - if( $wgDebugFunctionEntry ){
87 - $this->debug( str_repeat( ' ', count( $this->mWorkStack ) ) . 'Entering ' . $functionname . "\n" );
88 - }
89 -
90 - $this->mWorkStack[] = array( $functionname, count( $this->mWorkStack ), $this->getTime(), memory_get_usage() );
91 - }
92 -
93 - /**
94 - * Called by wfProfieOut()
95 - *
96 - * @param $functionname String
97 - */
98 - function profileOut($functionname) {
99 - global $wgDebugFunctionEntry, $wgProfiling;
100 - if( !$wgProfiling ) return;
101 - $memory = memory_get_usage();
102 - $time = $this->getTime();
103 -
104 - if( $wgDebugFunctionEntry ){
105 - $this->debug( str_repeat( ' ', count( $this->mWorkStack ) - 1 ) . 'Exiting ' . $functionname . "\n" );
106 - }
107 -
108 - $bit = array_pop($this->mWorkStack);
109 -
110 - if (!$bit) {
111 - $this->debug("Profiling error, !\$bit: $functionname\n");
112 - } else {
113 - //if( $wgDebugProfiling ){
114 - if( $functionname == 'close' ){
115 - $message = "Profile section ended by close(): {$bit[0]}";
116 - $this->debug( "$message\n" );
117 - $this->mStack[] = array( $message, 0, '0 0', 0, '0 0', 0 );
118 - }
119 - elseif( $bit[0] != $functionname ){
120 - $message = "Profiling error: in({$bit[0]}), out($functionname)";
121 - $this->debug( "$message\n" );
122 - $this->mStack[] = array( $message, 0, '0 0', 0, '0 0', 0 );
123 - }
124 - //}
125 - $bit[] = $time;
126 - $bit[] = $memory;
127 - $this->mStack[] = $bit;
128 - }
129 - }
130 -
131 - /**
132 - * called by wfProfileClose()
133 - */
134 - function close() {
135 - global $wgProfiling;
136 -
137 - # Avoid infinite loop
138 - if( !$wgProfiling )
139 - return;
140 -
141 - while( count( $this->mWorkStack ) ){
142 - $this->profileOut( 'close' );
143 - }
144 - }
145 -
146 - /**
147 - * Mark this call as templated or not
148 - *
149 - * @param $t Boolean
150 - */
151 - function setTemplated( $t ) {
152 - $this->mTemplated = $t;
153 - }
154 -
155 - /**
156 - * Called by wfGetProfilingOutput()
157 - */
158 - function getOutput() {
159 - global $wgDebugFunctionEntry, $wgProfileCallTree;
160 - $wgDebugFunctionEntry = false;
161 -
162 - if( !count( $this->mStack ) && !count( $this->mCollated ) ){
163 - return "No profiling output\n";
164 - }
165 - $this->close();
166 -
167 - if( $wgProfileCallTree ) {
168 - global $wgProfileToDatabase;
169 - # XXX: We must call $this->getFunctionReport() to log to the DB
170 - if( $wgProfileToDatabase ) {
171 - $this->getFunctionReport();
172 - }
173 - return $this->getCallTree();
174 - } else {
175 - return $this->getFunctionReport();
176 - }
177 - }
178 -
179 - /**
180 - * Returns a tree of function call instead of a list of functions
181 - */
182 - function getCallTree() {
183 - return implode( '', array_map( array( &$this, 'getCallTreeLine' ), $this->remapCallTree( $this->mStack ) ) );
184 - }
185 -
186 - /**
187 - * Recursive function the format the current profiling array into a tree
188 - *
189 - * @param $stack profiling array
190 - */
191 - function remapCallTree( $stack ) {
192 - if( count( $stack ) < 2 ){
193 - return $stack;
194 - }
195 - $outputs = array ();
196 - for( $max = count( $stack ) - 1; $max > 0; ){
197 - /* Find all items under this entry */
198 - $level = $stack[$max][1];
199 - $working = array ();
200 - for( $i = $max -1; $i >= 0; $i-- ){
201 - if( $stack[$i][1] > $level ){
202 - $working[] = $stack[$i];
203 - } else {
204 - break;
205 - }
206 - }
207 - $working = $this->remapCallTree( array_reverse( $working ) );
208 - $output = array();
209 - foreach( $working as $item ){
210 - array_push( $output, $item );
211 - }
212 - array_unshift( $output, $stack[$max] );
213 - $max = $i;
214 -
215 - array_unshift( $outputs, $output );
216 - }
217 - $final = array();
218 - foreach( $outputs as $output ){
219 - foreach( $output as $item ){
220 - $final[] = $item;
221 - }
222 - }
223 - return $final;
224 - }
225 -
226 - /**
227 - * Callback to get a formatted line for the call tree
228 - */
229 - function getCallTreeLine( $entry ) {
230 - list( $fname, $level, $start, /* $x */, $end) = $entry;
231 - $delta = $end - $start;
232 - $space = str_repeat(' ', $level);
233 - # The ugly double sprintf is to work around a PHP bug,
234 - # which has been fixed in recent releases.
235 - return sprintf( "%10s %s %s\n", trim( sprintf( "%7.3f", $delta * 1000.0 ) ), $space, $fname );
236 - }
237 -
238 - function getTime() {
239 - return microtime(true);
240 - #return $this->getUserTime();
241 - }
242 -
243 - function getUserTime() {
244 - $ru = getrusage();
245 - return $ru['ru_utime.tv_sec'].' '.$ru['ru_utime.tv_usec'] / 1e6;
246 - }
247 -
248 - /**
249 - * Returns a list of profiled functions.
250 - * Also log it into the database if $wgProfileToDatabase is set to true.
251 - */
252 - function getFunctionReport() {
253 - global $wgProfileToDatabase;
254 -
255 - $width = 140;
256 - $nameWidth = $width - 65;
257 - $format = "%-{$nameWidth}s %6d %13.3f %13.3f %13.3f%% %9d (%13.3f -%13.3f) [%d]\n";
258 - $titleFormat = "%-{$nameWidth}s %6s %13s %13s %13s %9s\n";
259 - $prof = "\nProfiling data\n";
260 - $prof .= sprintf( $titleFormat, 'Name', 'Calls', 'Total', 'Each', '%', 'Mem' );
261 - $this->mCollated = array ();
262 - $this->mCalls = array ();
263 - $this->mMemory = array ();
264 -
265 - # Estimate profiling overhead
266 - $profileCount = count($this->mStack);
267 - wfProfileIn( '-overhead-total' );
268 - for( $i = 0; $i < $profileCount; $i ++ ){
269 - wfProfileIn( '-overhead-internal' );
270 - wfProfileOut( '-overhead-internal' );
271 - }
272 - wfProfileOut( '-overhead-total' );
273 -
274 - # First, subtract the overhead!
275 - $overheadTotal = $overheadMemory = $overheadInternal = array();
276 - foreach( $this->mStack as $entry ){
277 - $fname = $entry[0];
278 - $start = $entry[2];
279 - $end = $entry[4];
280 - $elapsed = $end - $start;
281 - $memory = $entry[5] - $entry[3];
282 -
283 - if( $fname == '-overhead-total' ){
284 - $overheadTotal[] = $elapsed;
285 - $overheadMemory[] = $memory;
286 - }
287 - elseif( $fname == '-overhead-internal' ){
288 - $overheadInternal[] = $elapsed;
289 - }
290 - }
291 - $overheadTotal = $overheadTotal ? array_sum( $overheadTotal ) / count( $overheadInternal ) : 0;
292 - $overheadMemory = $overheadMemory ? array_sum( $overheadMemory ) / count( $overheadInternal ) : 0;
293 - $overheadInternal = $overheadInternal ? array_sum( $overheadInternal ) / count( $overheadInternal ) : 0;
294 -
295 - # Collate
296 - foreach( $this->mStack as $index => $entry ){
297 - $fname = $entry[0];
298 - $start = $entry[2];
299 - $end = $entry[4];
300 - $elapsed = $end - $start;
301 -
302 - $memory = $entry[5] - $entry[3];
303 - $subcalls = $this->calltreeCount( $this->mStack, $index );
304 -
305 - if( !preg_match( '/^-overhead/', $fname ) ){
306 - # Adjust for profiling overhead (except special values with elapsed=0
307 - if( $elapsed ) {
308 - $elapsed -= $overheadInternal;
309 - $elapsed -= ($subcalls * $overheadTotal);
310 - $memory -= ($subcalls * $overheadMemory);
311 - }
312 - }
313 -
314 - if( !array_key_exists( $fname, $this->mCollated ) ){
315 - $this->mCollated[$fname] = 0;
316 - $this->mCalls[$fname] = 0;
317 - $this->mMemory[$fname] = 0;
318 - $this->mMin[$fname] = 1 << 24;
319 - $this->mMax[$fname] = 0;
320 - $this->mOverhead[$fname] = 0;
321 - }
322 -
323 - $this->mCollated[$fname] += $elapsed;
324 - $this->mCalls[$fname]++;
325 - $this->mMemory[$fname] += $memory;
326 - $this->mMin[$fname] = min($this->mMin[$fname], $elapsed);
327 - $this->mMax[$fname] = max($this->mMax[$fname], $elapsed);
328 - $this->mOverhead[$fname] += $subcalls;
329 - }
330 -
331 - $total = @$this->mCollated['-total'];
332 - $this->mCalls['-overhead-total'] = $profileCount;
333 -
334 - # Output
335 - arsort( $this->mCollated, SORT_NUMERIC );
336 - foreach( $this->mCollated as $fname => $elapsed ){
337 - $calls = $this->mCalls[$fname];
338 - $percent = $total ? 100. * $elapsed / $total : 0;
339 - $memory = $this->mMemory[$fname];
340 - $prof .= sprintf($format, substr($fname, 0, $nameWidth), $calls, (float) ($elapsed * 1000), (float) ($elapsed * 1000) / $calls, $percent, $memory, ($this->mMin[$fname] * 1000.0), ($this->mMax[$fname] * 1000.0), $this->mOverhead[$fname]);
341 - # Log to the DB
342 - if( $wgProfileToDatabase ) {
343 - self::logToDB($fname, (float) ($elapsed * 1000), $calls, (float) ($memory) );
344 - }
345 - }
346 - $prof .= "\nTotal: $total\n\n";
347 -
348 - return $prof;
349 - }
350 -
351 - /**
352 - * Counts the number of profiled function calls sitting under
353 - * the given point in the call graph. Not the most efficient algo.
354 - *
355 - * @param $stack Array:
356 - * @param $start Integer:
357 - * @return Integer
358 - * @private
359 - */
360 - function calltreeCount($stack, $start) {
361 - $level = $stack[$start][1];
362 - $count = 0;
363 - for ($i = $start -1; $i >= 0 && $stack[$i][1] > $level; $i --) {
364 - $count ++;
365 - }
366 - return $count;
367 - }
368 -
369 - /**
370 - * Log a function into the database.
371 - *
372 - * @param $name String: function name
373 - * @param $timeSum Float
374 - * @param $eventCount Integer: number of times that function was called
375 - * @param $memorySum Integer: memory used by the function
376 - */
377 - static function logToDB( $name, $timeSum, $eventCount, $memorySum ){
378 - # Do not log anything if database is readonly (bug 5375)
379 - if( wfReadOnly() ) { return; }
380 -
381 - global $wgProfilePerHost;
382 -
383 - $dbw = wfGetDB( DB_MASTER );
384 - if( !is_object( $dbw ) )
385 - return false;
386 - $errorState = $dbw->ignoreErrors( true );
387 -
388 - $name = substr($name, 0, 255);
389 -
390 - if( $wgProfilePerHost ){
391 - $pfhost = wfHostname();
392 - } else {
393 - $pfhost = '';
394 - }
395 -
396 - // Kludge
397 - $timeSum = ($timeSum >= 0) ? $timeSum : 0;
398 - $memorySum = ($memorySum >= 0) ? $memorySum : 0;
399 -
400 - $dbw->update( 'profiling',
401 - array(
402 - "pf_count=pf_count+{$eventCount}",
403 - "pf_time=pf_time+{$timeSum}",
404 - "pf_memory=pf_memory+{$memorySum}",
405 - ),
406 - array(
407 - 'pf_name' => $name,
408 - 'pf_server' => $pfhost,
409 - ),
410 - __METHOD__ );
411 -
412 -
413 - $rc = $dbw->affectedRows();
414 - if ($rc == 0) {
415 - $dbw->insert('profiling', array ('pf_name' => $name, 'pf_count' => $eventCount,
416 - 'pf_time' => $timeSum, 'pf_memory' => $memorySum, 'pf_server' => $pfhost ),
417 - __METHOD__, array ('IGNORE'));
418 - }
419 - // When we upgrade to mysql 4.1, the insert+update
420 - // can be merged into just a insert with this construct added:
421 - // "ON DUPLICATE KEY UPDATE ".
422 - // "pf_count=pf_count + VALUES(pf_count), ".
423 - // "pf_time=pf_time + VALUES(pf_time)";
424 - $dbw->ignoreErrors( $errorState );
425 - }
426 -
427 - /**
428 - * Get the function name of the current profiling section
429 - */
430 - function getCurrentSection() {
431 - $elt = end( $this->mWorkStack );
432 - return $elt[0];
433 - }
434 -
435 - /**
436 - * Get function caller
437 - *
438 - * @param $level Integer
439 - */
440 - static function getCaller( $level ) {
441 - $backtrace = wfDebugBacktrace();
442 - if ( isset( $backtrace[$level] ) ) {
443 - if ( isset( $backtrace[$level]['class'] ) ) {
444 - $caller = $backtrace[$level]['class'] . '::' . $backtrace[$level]['function'];
445 - } else {
446 - $caller = $backtrace[$level]['function'];
447 - }
448 - } else {
449 - $caller = 'unknown';
450 - }
451 - return $caller;
452 - }
453 -
454 - /**
455 - * Add an entry in the debug log file
456 - *
457 - * @param $s String to output
458 - */
459 - function debug( $s ) {
460 - if( function_exists( 'wfDebug' ) ) {
461 - wfDebug( $s );
462 - }
463 - }
464 -}
Index: trunk/phase3/includes/ProfilerSimpleTrace.php
@@ -1,72 +0,0 @@
2 -<?php
3 -/**
4 - * @file
5 - * @ingroup Profiler
6 - */
7 -
8 -if ( !class_exists( 'ProfilerSimple' ) ) {
9 - require_once(dirname(__FILE__).'/ProfilerSimple.php');
10 -}
11 -
12 -/**
13 - * Execution trace
14 - * @todo document methods (?)
15 - * @ingroup Profiler
16 - */
17 -class ProfilerSimpleTrace extends ProfilerSimple {
18 - var $mMinimumTime = 0;
19 - var $mProfileID = false;
20 - var $trace = "";
21 - var $memory = 0;
22 -
23 - function __construct() {
24 - global $wgRequestTime, $wgRUstart;
25 - if (!empty($wgRequestTime) && !empty($wgRUstart)) {
26 - $this->mWorkStack[] = array( '-total', 0, $wgRequestTime,$this->getCpuTime($wgRUstart));
27 - $elapsedcpu = $this->getCpuTime() - $this->getCpuTime($wgRUstart);
28 - $elapsedreal = microtime(true) - $wgRequestTime;
29 - }
30 - $this->trace .= "Beginning trace: \n";
31 - }
32 -
33 - function profileIn($functionname) {
34 - $this->mWorkStack[] = array($functionname, count( $this->mWorkStack ), microtime(true), $this->getCpuTime());
35 - $this->trace .= " " . sprintf("%6.1f",$this->memoryDiff()) . str_repeat( " ", count($this->mWorkStack)) . " > " . $functionname . "\n";
36 - }
37 -
38 - function profileOut($functionname) {
39 - global $wgDebugFunctionEntry;
40 -
41 - if ($wgDebugFunctionEntry) {
42 - $this->debug(str_repeat(' ', count($this->mWorkStack) - 1).'Exiting '.$functionname."\n");
43 - }
44 -
45 - list($ofname, /* $ocount */ ,$ortime,$octime) = array_pop($this->mWorkStack);
46 -
47 - if (!$ofname) {
48 - $this->trace .= "Profiling error: $functionname\n";
49 - } else {
50 - if ($functionname == 'close') {
51 - $message = "Profile section ended by close(): {$ofname}";
52 - $functionname = $ofname;
53 - $this->trace .= $message . "\n";
54 - }
55 - elseif ($ofname != $functionname) {
56 - $this->trace .= "Profiling error: in({$ofname}), out($functionname)";
57 - }
58 - $elapsedcpu = $this->getCpuTime() - $octime;
59 - $elapsedreal = microtime(true) - $ortime;
60 - $this->trace .= sprintf("%03.6f %6.1f",$elapsedreal,$this->memoryDiff()) . str_repeat(" ",count($this->mWorkStack)+1) . " < " . $functionname . "\n";
61 - }
62 - }
63 -
64 - function memoryDiff() {
65 - $diff = memory_get_usage() - $this->memory;
66 - $this->memory = memory_get_usage();
67 - return $diff/1024;
68 - }
69 -
70 - function getOutput() {
71 - print "<!-- \n {$this->trace} \n -->";
72 - }
73 -}
Index: trunk/phase3/includes/ProfilerSimple.php
@@ -1,130 +0,0 @@
2 -<?php
3 -/**
4 - * @file
5 - * @ingroup Profiler
6 - */
7 -
8 -if ( !class_exists( 'Profiler' ) ) {
9 - require_once(dirname(__FILE__).'/Profiler.php');
10 -}
11 -
12 -/**
13 - * Simple profiler base class.
14 - * @todo document methods (?)
15 - * @ingroup Profiler
16 - */
17 -class ProfilerSimple extends Profiler {
18 - var $mMinimumTime = 0;
19 - var $mProfileID = false;
20 -
21 - function __construct() {
22 - global $wgRequestTime, $wgRUstart;
23 - if (!empty($wgRequestTime) && !empty($wgRUstart)) {
24 - $this->mWorkStack[] = array( '-total', 0, $wgRequestTime,$this->getCpuTime($wgRUstart));
25 -
26 - $elapsedcpu = $this->getCpuTime() - $this->getCpuTime($wgRUstart);
27 - $elapsedreal = microtime(true) - $wgRequestTime;
28 -
29 - $entry =& $this->mCollated["-setup"];
30 - if (!is_array($entry)) {
31 - $entry = array('cpu'=> 0.0, 'cpu_sq' => 0.0, 'real' => 0.0, 'real_sq' => 0.0, 'count' => 0);
32 - $this->mCollated["-setup"] =& $entry;
33 - }
34 - $entry['cpu'] += $elapsedcpu;
35 - $entry['cpu_sq'] += $elapsedcpu*$elapsedcpu;
36 - $entry['real'] += $elapsedreal;
37 - $entry['real_sq'] += $elapsedreal*$elapsedreal;
38 - $entry['count']++;
39 - }
40 - }
41 -
42 - function setMinimum( $min ) {
43 - $this->mMinimumTime = $min;
44 - }
45 -
46 - function setProfileID( $id ) {
47 - $this->mProfileID = $id;
48 - }
49 -
50 - function getProfileID() {
51 - if ( $this->mProfileID === false ) {
52 - return wfWikiID();
53 - } else {
54 - return $this->mProfileID;
55 - }
56 - }
57 -
58 - function profileIn($functionname) {
59 - global $wgDebugFunctionEntry;
60 - if ($wgDebugFunctionEntry) {
61 - $this->debug(str_repeat(' ', count($this->mWorkStack)).'Entering '.$functionname."\n");
62 - }
63 - $this->mWorkStack[] = array($functionname, count( $this->mWorkStack ), microtime(true), $this->getCpuTime());
64 - }
65 -
66 - function profileOut($functionname) {
67 - global $wgDebugFunctionEntry;
68 -
69 - if ($wgDebugFunctionEntry) {
70 - $this->debug(str_repeat(' ', count($this->mWorkStack) - 1).'Exiting '.$functionname."\n");
71 - }
72 -
73 - list($ofname, /* $ocount */ ,$ortime,$octime) = array_pop($this->mWorkStack);
74 -
75 - if (!$ofname) {
76 - $this->debug("Profiling error: $functionname\n");
77 - } else {
78 - if ($functionname == 'close') {
79 - $message = "Profile section ended by close(): {$ofname}";
80 - $functionname = $ofname;
81 - $this->debug( "$message\n" );
82 - $this->mCollated[$message] = array(
83 - 'real' => 0.0, 'count' => 1);
84 - }
85 - elseif ($ofname != $functionname) {
86 - $message = "Profiling error: in({$ofname}), out($functionname)";
87 - $this->debug( "$message\n" );
88 - $this->mCollated[$message] = array(
89 - 'real' => 0.0, 'count' => 1);
90 - }
91 - $entry =& $this->mCollated[$functionname];
92 - $elapsedcpu = $this->getCpuTime() - $octime;
93 - $elapsedreal = microtime(true) - $ortime;
94 - if (!is_array($entry)) {
95 - $entry = array('cpu'=> 0.0, 'cpu_sq' => 0.0, 'real' => 0.0, 'real_sq' => 0.0, 'count' => 0);
96 - $this->mCollated[$functionname] =& $entry;
97 - }
98 - $entry['cpu'] += $elapsedcpu;
99 - $entry['cpu_sq'] += $elapsedcpu*$elapsedcpu;
100 - $entry['real'] += $elapsedreal;
101 - $entry['real_sq'] += $elapsedreal*$elapsedreal;
102 - $entry['count']++;
103 -
104 - }
105 - }
106 -
107 - function getFunctionReport() {
108 - /* Implement in output subclasses */
109 - }
110 -
111 - function getCpuTime($ru=null) {
112 - if ( function_exists( 'getrusage' ) ) {
113 - if ( $ru == null ) {
114 - $ru = getrusage();
115 - }
116 - return ($ru['ru_utime.tv_sec'] + $ru['ru_stime.tv_sec'] + ($ru['ru_utime.tv_usec'] +
117 - $ru['ru_stime.tv_usec']) * 1e-6);
118 - } else {
119 - return 0;
120 - }
121 - }
122 -
123 - /* If argument is passed, it assumes that it is dual-format time string, returns proper float time value */
124 - function getTime($time=null) {
125 - if ($time==null) {
126 - return microtime(true);
127 - }
128 - list($a,$b)=explode(" ",$time);
129 - return (float)($a+$b);
130 - }
131 -}
Index: trunk/phase3/includes/ProfilerSimpleUDP.php
@@ -1,41 +0,0 @@
2 -<?php
3 -/**
4 - * @file
5 - * @ingroup Profiler
6 - */
7 -
8 -require_once(dirname(__FILE__).'/ProfilerSimple.php');
9 -
10 -/**
11 - * ProfilerSimpleUDP class, that sends out messages for 'udpprofile' daemon
12 - * (the one from mediawiki/trunk/udpprofile SVN )
13 - * @ingroup Profiler
14 - */
15 -class ProfilerSimpleUDP extends ProfilerSimple {
16 - function getFunctionReport() {
17 - global $wgUDPProfilerHost, $wgUDPProfilerPort;
18 -
19 - if ( $this->mCollated['-total']['real'] < $this->mMinimumTime ) {
20 - # Less than minimum, ignore
21 - return;
22 - }
23 -
24 - $sock = socket_create(AF_INET, SOCK_DGRAM, SOL_UDP);
25 - $plength=0;
26 - $packet="";
27 - foreach ($this->mCollated as $entry=>$pfdata) {
28 - $pfline=sprintf ("%s %s %d %f %f %f %f %s\n", $this->getProfileID(),"-",$pfdata['count'],
29 - $pfdata['cpu'],$pfdata['cpu_sq'],$pfdata['real'],$pfdata['real_sq'],$entry);
30 - $length=strlen($pfline);
31 - /* printf("<!-- $pfline -->"); */
32 - if ($length+$plength>1400) {
33 - socket_sendto($sock,$packet,$plength,0,$wgUDPProfilerHost,$wgUDPProfilerPort);
34 - $packet="";
35 - $plength=0;
36 - }
37 - $packet.=$pfline;
38 - $plength+=$length;
39 - }
40 - socket_sendto($sock,$packet,$plength,0x100,$wgUDPProfilerHost,$wgUDPProfilerPort);
41 - }
42 -}
Index: trunk/phase3/includes/profiler/ProfilerSimpleTrace.php
@@ -0,0 +1,72 @@
 2+<?php
 3+/**
 4+ * @file
 5+ * @ingroup Profiler
 6+ */
 7+
 8+if ( !class_exists( 'ProfilerSimple' ) ) {
 9+ require_once(dirname(__FILE__).'/ProfilerSimple.php');
 10+}
 11+
 12+/**
 13+ * Execution trace
 14+ * @todo document methods (?)
 15+ * @ingroup Profiler
 16+ */
 17+class ProfilerSimpleTrace extends ProfilerSimple {
 18+ var $mMinimumTime = 0;
 19+ var $mProfileID = false;
 20+ var $trace = "";
 21+ var $memory = 0;
 22+
 23+ function __construct() {
 24+ global $wgRequestTime, $wgRUstart;
 25+ if (!empty($wgRequestTime) && !empty($wgRUstart)) {
 26+ $this->mWorkStack[] = array( '-total', 0, $wgRequestTime,$this->getCpuTime($wgRUstart));
 27+ $elapsedcpu = $this->getCpuTime() - $this->getCpuTime($wgRUstart);
 28+ $elapsedreal = microtime(true) - $wgRequestTime;
 29+ }
 30+ $this->trace .= "Beginning trace: \n";
 31+ }
 32+
 33+ function profileIn($functionname) {
 34+ $this->mWorkStack[] = array($functionname, count( $this->mWorkStack ), microtime(true), $this->getCpuTime());
 35+ $this->trace .= " " . sprintf("%6.1f",$this->memoryDiff()) . str_repeat( " ", count($this->mWorkStack)) . " > " . $functionname . "\n";
 36+ }
 37+
 38+ function profileOut($functionname) {
 39+ global $wgDebugFunctionEntry;
 40+
 41+ if ($wgDebugFunctionEntry) {
 42+ $this->debug(str_repeat(' ', count($this->mWorkStack) - 1).'Exiting '.$functionname."\n");
 43+ }
 44+
 45+ list($ofname, /* $ocount */ ,$ortime,$octime) = array_pop($this->mWorkStack);
 46+
 47+ if (!$ofname) {
 48+ $this->trace .= "Profiling error: $functionname\n";
 49+ } else {
 50+ if ($functionname == 'close') {
 51+ $message = "Profile section ended by close(): {$ofname}";
 52+ $functionname = $ofname;
 53+ $this->trace .= $message . "\n";
 54+ }
 55+ elseif ($ofname != $functionname) {
 56+ $this->trace .= "Profiling error: in({$ofname}), out($functionname)";
 57+ }
 58+ $elapsedcpu = $this->getCpuTime() - $octime;
 59+ $elapsedreal = microtime(true) - $ortime;
 60+ $this->trace .= sprintf("%03.6f %6.1f",$elapsedreal,$this->memoryDiff()) . str_repeat(" ",count($this->mWorkStack)+1) . " < " . $functionname . "\n";
 61+ }
 62+ }
 63+
 64+ function memoryDiff() {
 65+ $diff = memory_get_usage() - $this->memory;
 66+ $this->memory = memory_get_usage();
 67+ return $diff/1024;
 68+ }
 69+
 70+ function getOutput() {
 71+ print "<!-- \n {$this->trace} \n -->";
 72+ }
 73+}
Property changes on: trunk/phase3/includes/profiler/ProfilerSimpleTrace.php
___________________________________________________________________
Added: svn:eol-style
174 + native
Index: trunk/phase3/includes/profiler/ProfilerSimple.php
@@ -0,0 +1,130 @@
 2+<?php
 3+/**
 4+ * @file
 5+ * @ingroup Profiler
 6+ */
 7+
 8+if ( !class_exists( 'Profiler' ) ) {
 9+ require_once(dirname(__FILE__).'/Profiler.php');
 10+}
 11+
 12+/**
 13+ * Simple profiler base class.
 14+ * @todo document methods (?)
 15+ * @ingroup Profiler
 16+ */
 17+class ProfilerSimple extends Profiler {
 18+ var $mMinimumTime = 0;
 19+ var $mProfileID = false;
 20+
 21+ function __construct() {
 22+ global $wgRequestTime, $wgRUstart;
 23+ if (!empty($wgRequestTime) && !empty($wgRUstart)) {
 24+ $this->mWorkStack[] = array( '-total', 0, $wgRequestTime,$this->getCpuTime($wgRUstart));
 25+
 26+ $elapsedcpu = $this->getCpuTime() - $this->getCpuTime($wgRUstart);
 27+ $elapsedreal = microtime(true) - $wgRequestTime;
 28+
 29+ $entry =& $this->mCollated["-setup"];
 30+ if (!is_array($entry)) {
 31+ $entry = array('cpu'=> 0.0, 'cpu_sq' => 0.0, 'real' => 0.0, 'real_sq' => 0.0, 'count' => 0);
 32+ $this->mCollated["-setup"] =& $entry;
 33+ }
 34+ $entry['cpu'] += $elapsedcpu;
 35+ $entry['cpu_sq'] += $elapsedcpu*$elapsedcpu;
 36+ $entry['real'] += $elapsedreal;
 37+ $entry['real_sq'] += $elapsedreal*$elapsedreal;
 38+ $entry['count']++;
 39+ }
 40+ }
 41+
 42+ function setMinimum( $min ) {
 43+ $this->mMinimumTime = $min;
 44+ }
 45+
 46+ function setProfileID( $id ) {
 47+ $this->mProfileID = $id;
 48+ }
 49+
 50+ function getProfileID() {
 51+ if ( $this->mProfileID === false ) {
 52+ return wfWikiID();
 53+ } else {
 54+ return $this->mProfileID;
 55+ }
 56+ }
 57+
 58+ function profileIn($functionname) {
 59+ global $wgDebugFunctionEntry;
 60+ if ($wgDebugFunctionEntry) {
 61+ $this->debug(str_repeat(' ', count($this->mWorkStack)).'Entering '.$functionname."\n");
 62+ }
 63+ $this->mWorkStack[] = array($functionname, count( $this->mWorkStack ), microtime(true), $this->getCpuTime());
 64+ }
 65+
 66+ function profileOut($functionname) {
 67+ global $wgDebugFunctionEntry;
 68+
 69+ if ($wgDebugFunctionEntry) {
 70+ $this->debug(str_repeat(' ', count($this->mWorkStack) - 1).'Exiting '.$functionname."\n");
 71+ }
 72+
 73+ list($ofname, /* $ocount */ ,$ortime,$octime) = array_pop($this->mWorkStack);
 74+
 75+ if (!$ofname) {
 76+ $this->debug("Profiling error: $functionname\n");
 77+ } else {
 78+ if ($functionname == 'close') {
 79+ $message = "Profile section ended by close(): {$ofname}";
 80+ $functionname = $ofname;
 81+ $this->debug( "$message\n" );
 82+ $this->mCollated[$message] = array(
 83+ 'real' => 0.0, 'count' => 1);
 84+ }
 85+ elseif ($ofname != $functionname) {
 86+ $message = "Profiling error: in({$ofname}), out($functionname)";
 87+ $this->debug( "$message\n" );
 88+ $this->mCollated[$message] = array(
 89+ 'real' => 0.0, 'count' => 1);
 90+ }
 91+ $entry =& $this->mCollated[$functionname];
 92+ $elapsedcpu = $this->getCpuTime() - $octime;
 93+ $elapsedreal = microtime(true) - $ortime;
 94+ if (!is_array($entry)) {
 95+ $entry = array('cpu'=> 0.0, 'cpu_sq' => 0.0, 'real' => 0.0, 'real_sq' => 0.0, 'count' => 0);
 96+ $this->mCollated[$functionname] =& $entry;
 97+ }
 98+ $entry['cpu'] += $elapsedcpu;
 99+ $entry['cpu_sq'] += $elapsedcpu*$elapsedcpu;
 100+ $entry['real'] += $elapsedreal;
 101+ $entry['real_sq'] += $elapsedreal*$elapsedreal;
 102+ $entry['count']++;
 103+
 104+ }
 105+ }
 106+
 107+ function getFunctionReport() {
 108+ /* Implement in output subclasses */
 109+ }
 110+
 111+ function getCpuTime($ru=null) {
 112+ if ( function_exists( 'getrusage' ) ) {
 113+ if ( $ru == null ) {
 114+ $ru = getrusage();
 115+ }
 116+ return ($ru['ru_utime.tv_sec'] + $ru['ru_stime.tv_sec'] + ($ru['ru_utime.tv_usec'] +
 117+ $ru['ru_stime.tv_usec']) * 1e-6);
 118+ } else {
 119+ return 0;
 120+ }
 121+ }
 122+
 123+ /* If argument is passed, it assumes that it is dual-format time string, returns proper float time value */
 124+ function getTime($time=null) {
 125+ if ($time==null) {
 126+ return microtime(true);
 127+ }
 128+ list($a,$b)=explode(" ",$time);
 129+ return (float)($a+$b);
 130+ }
 131+}
Property changes on: trunk/phase3/includes/profiler/ProfilerSimple.php
___________________________________________________________________
Added: svn:keywords
1132 + Author Date Id Revision
Added: svn:eol-style
2133 + native
Index: trunk/phase3/includes/profiler/ProfilerStub.php
@@ -0,0 +1,52 @@
 2+<?php
 3+/**
 4+ * Stub profiling functions
 5+ * @file
 6+ * @ingroup Profiler
 7+ */
 8+
 9+/** backward compatibility */
 10+$wgProfiling = false;
 11+$wgProfiler = null;
 12+
 13+/** is setproctitle function available ? */
 14+$haveProctitle = function_exists( 'setproctitle' );
 15+
 16+/**
 17+ * Begin profiling of a function
 18+ * @param $fn string
 19+ */
 20+function wfProfileIn( $fn = '' ) {
 21+ global $hackwhere, $wgDBname, $haveProctitle;
 22+ if( $haveProctitle ){
 23+ $hackwhere[] = $fn;
 24+ setproctitle( $fn . " [$wgDBname]" );
 25+ }
 26+}
 27+
 28+/**
 29+ * Stop profiling of a function
 30+ * @param $fn string
 31+ */
 32+function wfProfileOut( $fn = '' ) {
 33+ global $hackwhere, $wgDBname, $haveProctitle;
 34+ if( !$haveProctitle ) {
 35+ return;
 36+ }
 37+ if( count( $hackwhere ) ) {
 38+ array_pop( $hackwhere );
 39+ }
 40+ if( count( $hackwhere ) ) {
 41+ setproctitle( $hackwhere[count( $hackwhere )-1] . " [$wgDBname]" );
 42+ }
 43+}
 44+
 45+/**
 46+ * Does nothing, just for compatibility
 47+ */
 48+function wfGetProfilingOutput( $s, $e ) {}
 49+
 50+/**
 51+ * Does nothing, just for compatibility
 52+ */
 53+function wfProfileClose() {}
Property changes on: trunk/phase3/includes/profiler/ProfilerStub.php
___________________________________________________________________
Added: svn:keywords
154 + Author Date Id Revision
Added: svn:eol-style
255 + native
Index: trunk/phase3/includes/profiler/ProfilerSimpleText.php
@@ -0,0 +1,39 @@
 2+<?php
 3+/**
 4+ * @file
 5+ * @ingroup Profiler
 6+ */
 7+
 8+require_once( dirname( __FILE__ ) . '/ProfilerSimple.php' );
 9+
 10+/**
 11+ * The least sophisticated profiler output class possible, view your source! :)
 12+ *
 13+ * Put the following 3 lines in StartProfiler.php:
 14+ *
 15+ * require_once( dirname( __FILE__ ) . '/includes/ProfilerSimpleText.php' );
 16+ * $wgProfiler = new ProfilerSimpleText;
 17+ * $wgProfiler->visible=true;
 18+ *
 19+ * @ingroup Profiler
 20+ */
 21+class ProfilerSimpleText extends ProfilerSimple {
 22+ public $visible=false; /* Show as <PRE> or <!-- ? */
 23+ static private $out;
 24+
 25+ function getFunctionReport() {
 26+ if($this->mTemplated) {
 27+ uasort($this->mCollated,array('self','sort'));
 28+ array_walk($this->mCollated,array('self','format'));
 29+ if ($this->visible) {
 30+ print '<pre>'.self::$out.'</pre>';
 31+ } else {
 32+ print "<!--\n".self::$out."\n-->\n";
 33+ }
 34+ }
 35+ }
 36+
 37+ /* dense is good */
 38+ static function sort($a,$b) { return $a['real']<$b['real']; /* sort descending by time elapsed */ }
 39+ static function format($item,$key) { self::$out .= sprintf("%3.6f %6d - %s\n",$item['real'],$item['count'], $key); }
 40+}
Property changes on: trunk/phase3/includes/profiler/ProfilerSimpleText.php
___________________________________________________________________
Added: svn:eol-style
141 + native
Index: trunk/phase3/includes/profiler/Profiler.php
@@ -0,0 +1,463 @@
 2+<?php
 3+/**
 4+ * @defgroup Profiler Profiler
 5+ *
 6+ * @file
 7+ * @ingroup Profiler
 8+ * This file is only included if profiling is enabled
 9+ */
 10+
 11+/** backward compatibility */
 12+$wgProfiling = true;
 13+
 14+/**
 15+ * Begin profiling of a function
 16+ * @param $functionname String: name of the function we will profile
 17+ */
 18+function wfProfileIn( $functionname ) {
 19+ global $wgProfiler;
 20+ $wgProfiler->profileIn( $functionname );
 21+}
 22+
 23+/**
 24+ * Stop profiling of a function
 25+ * @param $functionname String: name of the function we have profiled
 26+ */
 27+function wfProfileOut( $functionname = 'missing' ) {
 28+ global $wgProfiler;
 29+ $wgProfiler->profileOut( $functionname );
 30+}
 31+
 32+/**
 33+ * Returns a profiling output to be stored in debug file
 34+ *
 35+ * @param $start Float
 36+ * @param $elapsed Float: time elapsed since the beginning of the request
 37+ */
 38+function wfGetProfilingOutput( $start, $elapsed ) {
 39+ global $wgProfiler;
 40+ return $wgProfiler->getOutput( $start, $elapsed );
 41+}
 42+
 43+/**
 44+ * Close opened profiling sections
 45+ */
 46+function wfProfileClose() {
 47+ global $wgProfiler;
 48+ $wgProfiler->close();
 49+}
 50+
 51+if (!function_exists('memory_get_usage')) {
 52+ # Old PHP or --enable-memory-limit not compiled in
 53+ function memory_get_usage() {
 54+ return 0;
 55+ }
 56+}
 57+
 58+/**
 59+ * @ingroup Profiler
 60+ * @todo document
 61+ */
 62+class Profiler {
 63+ var $mStack = array (), $mWorkStack = array (), $mCollated = array ();
 64+ var $mCalls = array (), $mTotals = array ();
 65+ var $mTemplated = false;
 66+
 67+ function __construct() {
 68+ // Push an entry for the pre-profile setup time onto the stack
 69+ global $wgRequestTime;
 70+ if ( !empty( $wgRequestTime ) ) {
 71+ $this->mWorkStack[] = array( '-total', 0, $wgRequestTime, 0 );
 72+ $this->mStack[] = array( '-setup', 1, $wgRequestTime, 0, microtime(true), 0 );
 73+ } else {
 74+ $this->profileIn( '-total' );
 75+ }
 76+ }
 77+
 78+ /**
 79+ * Called by wfProfieIn()
 80+ *
 81+ * @param $functionname String
 82+ */
 83+ function profileIn( $functionname ) {
 84+ global $wgDebugFunctionEntry, $wgProfiling;
 85+ if( !$wgProfiling ) return;
 86+ if( $wgDebugFunctionEntry ){
 87+ $this->debug( str_repeat( ' ', count( $this->mWorkStack ) ) . 'Entering ' . $functionname . "\n" );
 88+ }
 89+
 90+ $this->mWorkStack[] = array( $functionname, count( $this->mWorkStack ), $this->getTime(), memory_get_usage() );
 91+ }
 92+
 93+ /**
 94+ * Called by wfProfieOut()
 95+ *
 96+ * @param $functionname String
 97+ */
 98+ function profileOut($functionname) {
 99+ global $wgDebugFunctionEntry, $wgProfiling;
 100+ if( !$wgProfiling ) return;
 101+ $memory = memory_get_usage();
 102+ $time = $this->getTime();
 103+
 104+ if( $wgDebugFunctionEntry ){
 105+ $this->debug( str_repeat( ' ', count( $this->mWorkStack ) - 1 ) . 'Exiting ' . $functionname . "\n" );
 106+ }
 107+
 108+ $bit = array_pop($this->mWorkStack);
 109+
 110+ if (!$bit) {
 111+ $this->debug("Profiling error, !\$bit: $functionname\n");
 112+ } else {
 113+ //if( $wgDebugProfiling ){
 114+ if( $functionname == 'close' ){
 115+ $message = "Profile section ended by close(): {$bit[0]}";
 116+ $this->debug( "$message\n" );
 117+ $this->mStack[] = array( $message, 0, '0 0', 0, '0 0', 0 );
 118+ }
 119+ elseif( $bit[0] != $functionname ){
 120+ $message = "Profiling error: in({$bit[0]}), out($functionname)";
 121+ $this->debug( "$message\n" );
 122+ $this->mStack[] = array( $message, 0, '0 0', 0, '0 0', 0 );
 123+ }
 124+ //}
 125+ $bit[] = $time;
 126+ $bit[] = $memory;
 127+ $this->mStack[] = $bit;
 128+ }
 129+ }
 130+
 131+ /**
 132+ * called by wfProfileClose()
 133+ */
 134+ function close() {
 135+ global $wgProfiling;
 136+
 137+ # Avoid infinite loop
 138+ if( !$wgProfiling )
 139+ return;
 140+
 141+ while( count( $this->mWorkStack ) ){
 142+ $this->profileOut( 'close' );
 143+ }
 144+ }
 145+
 146+ /**
 147+ * Mark this call as templated or not
 148+ *
 149+ * @param $t Boolean
 150+ */
 151+ function setTemplated( $t ) {
 152+ $this->mTemplated = $t;
 153+ }
 154+
 155+ /**
 156+ * Called by wfGetProfilingOutput()
 157+ */
 158+ function getOutput() {
 159+ global $wgDebugFunctionEntry, $wgProfileCallTree;
 160+ $wgDebugFunctionEntry = false;
 161+
 162+ if( !count( $this->mStack ) && !count( $this->mCollated ) ){
 163+ return "No profiling output\n";
 164+ }
 165+ $this->close();
 166+
 167+ if( $wgProfileCallTree ) {
 168+ global $wgProfileToDatabase;
 169+ # XXX: We must call $this->getFunctionReport() to log to the DB
 170+ if( $wgProfileToDatabase ) {
 171+ $this->getFunctionReport();
 172+ }
 173+ return $this->getCallTree();
 174+ } else {
 175+ return $this->getFunctionReport();
 176+ }
 177+ }
 178+
 179+ /**
 180+ * Returns a tree of function call instead of a list of functions
 181+ */
 182+ function getCallTree() {
 183+ return implode( '', array_map( array( &$this, 'getCallTreeLine' ), $this->remapCallTree( $this->mStack ) ) );
 184+ }
 185+
 186+ /**
 187+ * Recursive function the format the current profiling array into a tree
 188+ *
 189+ * @param $stack profiling array
 190+ */
 191+ function remapCallTree( $stack ) {
 192+ if( count( $stack ) < 2 ){
 193+ return $stack;
 194+ }
 195+ $outputs = array ();
 196+ for( $max = count( $stack ) - 1; $max > 0; ){
 197+ /* Find all items under this entry */
 198+ $level = $stack[$max][1];
 199+ $working = array ();
 200+ for( $i = $max -1; $i >= 0; $i-- ){
 201+ if( $stack[$i][1] > $level ){
 202+ $working[] = $stack[$i];
 203+ } else {
 204+ break;
 205+ }
 206+ }
 207+ $working = $this->remapCallTree( array_reverse( $working ) );
 208+ $output = array();
 209+ foreach( $working as $item ){
 210+ array_push( $output, $item );
 211+ }
 212+ array_unshift( $output, $stack[$max] );
 213+ $max = $i;
 214+
 215+ array_unshift( $outputs, $output );
 216+ }
 217+ $final = array();
 218+ foreach( $outputs as $output ){
 219+ foreach( $output as $item ){
 220+ $final[] = $item;
 221+ }
 222+ }
 223+ return $final;
 224+ }
 225+
 226+ /**
 227+ * Callback to get a formatted line for the call tree
 228+ */
 229+ function getCallTreeLine( $entry ) {
 230+ list( $fname, $level, $start, /* $x */, $end) = $entry;
 231+ $delta = $end - $start;
 232+ $space = str_repeat(' ', $level);
 233+ # The ugly double sprintf is to work around a PHP bug,
 234+ # which has been fixed in recent releases.
 235+ return sprintf( "%10s %s %s\n", trim( sprintf( "%7.3f", $delta * 1000.0 ) ), $space, $fname );
 236+ }
 237+
 238+ function getTime() {
 239+ return microtime(true);
 240+ #return $this->getUserTime();
 241+ }
 242+
 243+ function getUserTime() {
 244+ $ru = getrusage();
 245+ return $ru['ru_utime.tv_sec'].' '.$ru['ru_utime.tv_usec'] / 1e6;
 246+ }
 247+
 248+ /**
 249+ * Returns a list of profiled functions.
 250+ * Also log it into the database if $wgProfileToDatabase is set to true.
 251+ */
 252+ function getFunctionReport() {
 253+ global $wgProfileToDatabase;
 254+
 255+ $width = 140;
 256+ $nameWidth = $width - 65;
 257+ $format = "%-{$nameWidth}s %6d %13.3f %13.3f %13.3f%% %9d (%13.3f -%13.3f) [%d]\n";
 258+ $titleFormat = "%-{$nameWidth}s %6s %13s %13s %13s %9s\n";
 259+ $prof = "\nProfiling data\n";
 260+ $prof .= sprintf( $titleFormat, 'Name', 'Calls', 'Total', 'Each', '%', 'Mem' );
 261+ $this->mCollated = array ();
 262+ $this->mCalls = array ();
 263+ $this->mMemory = array ();
 264+
 265+ # Estimate profiling overhead
 266+ $profileCount = count($this->mStack);
 267+ wfProfileIn( '-overhead-total' );
 268+ for( $i = 0; $i < $profileCount; $i ++ ){
 269+ wfProfileIn( '-overhead-internal' );
 270+ wfProfileOut( '-overhead-internal' );
 271+ }
 272+ wfProfileOut( '-overhead-total' );
 273+
 274+ # First, subtract the overhead!
 275+ $overheadTotal = $overheadMemory = $overheadInternal = array();
 276+ foreach( $this->mStack as $entry ){
 277+ $fname = $entry[0];
 278+ $start = $entry[2];
 279+ $end = $entry[4];
 280+ $elapsed = $end - $start;
 281+ $memory = $entry[5] - $entry[3];
 282+
 283+ if( $fname == '-overhead-total' ){
 284+ $overheadTotal[] = $elapsed;
 285+ $overheadMemory[] = $memory;
 286+ }
 287+ elseif( $fname == '-overhead-internal' ){
 288+ $overheadInternal[] = $elapsed;
 289+ }
 290+ }
 291+ $overheadTotal = $overheadTotal ? array_sum( $overheadTotal ) / count( $overheadInternal ) : 0;
 292+ $overheadMemory = $overheadMemory ? array_sum( $overheadMemory ) / count( $overheadInternal ) : 0;
 293+ $overheadInternal = $overheadInternal ? array_sum( $overheadInternal ) / count( $overheadInternal ) : 0;
 294+
 295+ # Collate
 296+ foreach( $this->mStack as $index => $entry ){
 297+ $fname = $entry[0];
 298+ $start = $entry[2];
 299+ $end = $entry[4];
 300+ $elapsed = $end - $start;
 301+
 302+ $memory = $entry[5] - $entry[3];
 303+ $subcalls = $this->calltreeCount( $this->mStack, $index );
 304+
 305+ if( !preg_match( '/^-overhead/', $fname ) ){
 306+ # Adjust for profiling overhead (except special values with elapsed=0
 307+ if( $elapsed ) {
 308+ $elapsed -= $overheadInternal;
 309+ $elapsed -= ($subcalls * $overheadTotal);
 310+ $memory -= ($subcalls * $overheadMemory);
 311+ }
 312+ }
 313+
 314+ if( !array_key_exists( $fname, $this->mCollated ) ){
 315+ $this->mCollated[$fname] = 0;
 316+ $this->mCalls[$fname] = 0;
 317+ $this->mMemory[$fname] = 0;
 318+ $this->mMin[$fname] = 1 << 24;
 319+ $this->mMax[$fname] = 0;
 320+ $this->mOverhead[$fname] = 0;
 321+ }
 322+
 323+ $this->mCollated[$fname] += $elapsed;
 324+ $this->mCalls[$fname]++;
 325+ $this->mMemory[$fname] += $memory;
 326+ $this->mMin[$fname] = min($this->mMin[$fname], $elapsed);
 327+ $this->mMax[$fname] = max($this->mMax[$fname], $elapsed);
 328+ $this->mOverhead[$fname] += $subcalls;
 329+ }
 330+
 331+ $total = @$this->mCollated['-total'];
 332+ $this->mCalls['-overhead-total'] = $profileCount;
 333+
 334+ # Output
 335+ arsort( $this->mCollated, SORT_NUMERIC );
 336+ foreach( $this->mCollated as $fname => $elapsed ){
 337+ $calls = $this->mCalls[$fname];
 338+ $percent = $total ? 100. * $elapsed / $total : 0;
 339+ $memory = $this->mMemory[$fname];
 340+ $prof .= sprintf($format, substr($fname, 0, $nameWidth), $calls, (float) ($elapsed * 1000), (float) ($elapsed * 1000) / $calls, $percent, $memory, ($this->mMin[$fname] * 1000.0), ($this->mMax[$fname] * 1000.0), $this->mOverhead[$fname]);
 341+ # Log to the DB
 342+ if( $wgProfileToDatabase ) {
 343+ self::logToDB($fname, (float) ($elapsed * 1000), $calls, (float) ($memory) );
 344+ }
 345+ }
 346+ $prof .= "\nTotal: $total\n\n";
 347+
 348+ return $prof;
 349+ }
 350+
 351+ /**
 352+ * Counts the number of profiled function calls sitting under
 353+ * the given point in the call graph. Not the most efficient algo.
 354+ *
 355+ * @param $stack Array:
 356+ * @param $start Integer:
 357+ * @return Integer
 358+ * @private
 359+ */
 360+ function calltreeCount($stack, $start) {
 361+ $level = $stack[$start][1];
 362+ $count = 0;
 363+ for ($i = $start -1; $i >= 0 && $stack[$i][1] > $level; $i --) {
 364+ $count ++;
 365+ }
 366+ return $count;
 367+ }
 368+
 369+ /**
 370+ * Log a function into the database.
 371+ *
 372+ * @param $name String: function name
 373+ * @param $timeSum Float
 374+ * @param $eventCount Integer: number of times that function was called
 375+ * @param $memorySum Integer: memory used by the function
 376+ */
 377+ static function logToDB( $name, $timeSum, $eventCount, $memorySum ){
 378+ # Do not log anything if database is readonly (bug 5375)
 379+ if( wfReadOnly() ) { return; }
 380+
 381+ global $wgProfilePerHost;
 382+
 383+ $dbw = wfGetDB( DB_MASTER );
 384+ if( !is_object( $dbw ) )
 385+ return false;
 386+ $errorState = $dbw->ignoreErrors( true );
 387+
 388+ $name = substr($name, 0, 255);
 389+
 390+ if( $wgProfilePerHost ){
 391+ $pfhost = wfHostname();
 392+ } else {
 393+ $pfhost = '';
 394+ }
 395+
 396+ // Kludge
 397+ $timeSum = ($timeSum >= 0) ? $timeSum : 0;
 398+ $memorySum = ($memorySum >= 0) ? $memorySum : 0;
 399+
 400+ $dbw->update( 'profiling',
 401+ array(
 402+ "pf_count=pf_count+{$eventCount}",
 403+ "pf_time=pf_time+{$timeSum}",
 404+ "pf_memory=pf_memory+{$memorySum}",
 405+ ),
 406+ array(
 407+ 'pf_name' => $name,
 408+ 'pf_server' => $pfhost,
 409+ ),
 410+ __METHOD__ );
 411+
 412+
 413+ $rc = $dbw->affectedRows();
 414+ if ($rc == 0) {
 415+ $dbw->insert('profiling', array ('pf_name' => $name, 'pf_count' => $eventCount,
 416+ 'pf_time' => $timeSum, 'pf_memory' => $memorySum, 'pf_server' => $pfhost ),
 417+ __METHOD__, array ('IGNORE'));
 418+ }
 419+ // When we upgrade to mysql 4.1, the insert+update
 420+ // can be merged into just a insert with this construct added:
 421+ // "ON DUPLICATE KEY UPDATE ".
 422+ // "pf_count=pf_count + VALUES(pf_count), ".
 423+ // "pf_time=pf_time + VALUES(pf_time)";
 424+ $dbw->ignoreErrors( $errorState );
 425+ }
 426+
 427+ /**
 428+ * Get the function name of the current profiling section
 429+ */
 430+ function getCurrentSection() {
 431+ $elt = end( $this->mWorkStack );
 432+ return $elt[0];
 433+ }
 434+
 435+ /**
 436+ * Get function caller
 437+ *
 438+ * @param $level Integer
 439+ */
 440+ static function getCaller( $level ) {
 441+ $backtrace = wfDebugBacktrace();
 442+ if ( isset( $backtrace[$level] ) ) {
 443+ if ( isset( $backtrace[$level]['class'] ) ) {
 444+ $caller = $backtrace[$level]['class'] . '::' . $backtrace[$level]['function'];
 445+ } else {
 446+ $caller = $backtrace[$level]['function'];
 447+ }
 448+ } else {
 449+ $caller = 'unknown';
 450+ }
 451+ return $caller;
 452+ }
 453+
 454+ /**
 455+ * Add an entry in the debug log file
 456+ *
 457+ * @param $s String to output
 458+ */
 459+ function debug( $s ) {
 460+ if( function_exists( 'wfDebug' ) ) {
 461+ wfDebug( $s );
 462+ }
 463+ }
 464+}
Property changes on: trunk/phase3/includes/profiler/Profiler.php
___________________________________________________________________
Added: svn:keywords
1465 + Author Date Id Revision
Added: svn:eol-style
2466 + native
Index: trunk/phase3/includes/profiler/ProfilerSimpleUDP.php
@@ -0,0 +1,41 @@
 2+<?php
 3+/**
 4+ * @file
 5+ * @ingroup Profiler
 6+ */
 7+
 8+require_once(dirname(__FILE__).'/ProfilerSimple.php');
 9+
 10+/**
 11+ * ProfilerSimpleUDP class, that sends out messages for 'udpprofile' daemon
 12+ * (the one from mediawiki/trunk/udpprofile SVN )
 13+ * @ingroup Profiler
 14+ */
 15+class ProfilerSimpleUDP extends ProfilerSimple {
 16+ function getFunctionReport() {
 17+ global $wgUDPProfilerHost, $wgUDPProfilerPort;
 18+
 19+ if ( $this->mCollated['-total']['real'] < $this->mMinimumTime ) {
 20+ # Less than minimum, ignore
 21+ return;
 22+ }
 23+
 24+ $sock = socket_create(AF_INET, SOCK_DGRAM, SOL_UDP);
 25+ $plength=0;
 26+ $packet="";
 27+ foreach ($this->mCollated as $entry=>$pfdata) {
 28+ $pfline=sprintf ("%s %s %d %f %f %f %f %s\n", $this->getProfileID(),"-",$pfdata['count'],
 29+ $pfdata['cpu'],$pfdata['cpu_sq'],$pfdata['real'],$pfdata['real_sq'],$entry);
 30+ $length=strlen($pfline);
 31+ /* printf("<!-- $pfline -->"); */
 32+ if ($length+$plength>1400) {
 33+ socket_sendto($sock,$packet,$plength,0,$wgUDPProfilerHost,$wgUDPProfilerPort);
 34+ $packet="";
 35+ $plength=0;
 36+ }
 37+ $packet.=$pfline;
 38+ $plength+=$length;
 39+ }
 40+ socket_sendto($sock,$packet,$plength,0x100,$wgUDPProfilerHost,$wgUDPProfilerPort);
 41+ }
 42+}
Property changes on: trunk/phase3/includes/profiler/ProfilerSimpleUDP.php
___________________________________________________________________
Added: svn:keywords
143 + Author Date Id Revision
Added: svn:eol-style
244 + native
Index: trunk/phase3/includes/AutoLoader.php
@@ -183,10 +183,10 @@
184184 'PoolCounterWork' => 'includes/PoolCounter.php',
185185 'Preferences' => 'includes/Preferences.php',
186186 'PrefixSearch' => 'includes/PrefixSearch.php',
187 - 'Profiler' => 'includes/Profiler.php',
188 - 'ProfilerSimple' => 'includes/ProfilerSimple.php',
189 - 'ProfilerSimpleText' => 'includes/ProfilerSimpleText.php',
190 - 'ProfilerSimpleUDP' => 'includes/ProfilerSimpleUDP.php',
 187+ 'Profiler' => 'includes/profiler/Profiler.php',
 188+ 'ProfilerSimple' => 'includes/profiler/ProfilerSimple.php',
 189+ 'ProfilerSimpleText' => 'includes/profiler/ProfilerSimpleText.php',
 190+ 'ProfilerSimpleUDP' => 'includes/profiler/ProfilerSimpleUDP.php',
191191 'ProtectionForm' => 'includes/ProtectionForm.php',
192192 'QueryPage' => 'includes/QueryPage.php',
193193 'QuickTemplate' => 'includes/SkinTemplate.php',

Follow-up revisions

RevisionCommit summaryAuthorDate
r74922Revert r74913, caused many problems, and was only likely to cause more in the...reedy21:18, 17 October 2010

Comments

#Comment by Raymond (talk | contribs)   19:56, 17 October 2010

Seen on translatewiki:

Warning: require_once(/www/w/includes/ProfilerStub.php): failed to open stream: No such file or directory in /www/w/maintenance/doMaintenance.php on line 58

Fatal error: require_once(): Failed opening required '/www/w/includes/ProfilerStub.php' (include_path='.:/usr/share/php:/usr/share/pear') in /www/w/maintenance/doMaintenance.php on line 58

#Comment by Hashar (talk | contribs)   20:27, 17 October 2010

This revision should get a big warning flag since it will impact live deployment.

#Comment by Catrope (talk | contribs)   20:39, 17 October 2010

How would it impact deployment, once the issue Raymond mentioned is fixed?

#Comment by Platonides (talk | contribs)   20:54, 17 October 2010

Profiling instructions tell people to create a StartProfiler.php file, which is loaded automatically both from doMaintenance.php and WebStart.php It would contain a require for includes/Profiler.php which would now give a fatal.

Someone which had profiling enabled would have its wiki inaccesible on update.

I'm thinking we should rename StartProfiler.php as well. Disabling profiling is better than producing a fatal.

#Comment by Reedy (talk | contribs)   21:00, 17 October 2010

Is this going to be simpler (in the long run) just to revert?

Status & tagging log