New 'profileerror' log group for profiling errors
authorAlexandre Emsenhuber <mediawiki@emsenhuber.ch>
Sat, 15 Mar 2014 20:43:39 +0000 (21:43 +0100)
committerAlexandre Emsenhuber <mediawiki@emsenhuber.ch>
Sat, 15 Mar 2014 20:43:39 +0000 (21:43 +0100)
Easier to catch them than if they are in the default debug log.

Added Profiler::debugGroup() as wrapper to wfDebugLog(), as
there already is Profiler::debug() for wfDebug(), so that
there won't be a fatal error if the error happens before the
inclusion of GlobalFunctions.php and converted other calls
to wfDebugLog() to use it.

Change-Id: Ie8481a2e13a94efa0248dd5a36b6b1a22811817e

includes/profiler/Profiler.php
includes/profiler/ProfilerMwprof.php
includes/profiler/ProfilerSimple.php

index 235a5ad..a26ef68 100644 (file)
@@ -227,15 +227,17 @@ class Profiler {
                $bit = array_pop( $this->mWorkStack );
 
                if ( !$bit ) {
-                       $this->debug( "Profiling error, !\$bit: $functionname\n" );
+                       $this->debugGroup( 'profileerror', "Profiling error, !\$bit: $functionname" );
                } else {
                        if ( $functionname == 'close' ) {
-                               $message = "Profile section ended by close(): {$bit[0]}";
-                               $this->debug( "$message\n" );
-                               $this->mStack[] = array( $message, 0, 0.0, 0, 0.0, 0 );
+                               if ( $bit[0] != '-total' ) {
+                                       $message = "Profile section ended by close(): {$bit[0]}";
+                                       $this->debugGroup( 'profileerror', $message );
+                                       $this->mStack[] = array( $message, 0, 0.0, 0, 0.0, 0 );
+                               }
                        } elseif ( $bit[0] != $functionname ) {
                                $message = "Profiling error: in({$bit[0]}), out($functionname)";
-                               $this->debug( "$message\n" );
+                               $this->debugGroup( 'profileerror', $message );
                                $this->mStack[] = array( $message, 0, 0.0, 0, 0.0, 0 );
                        }
                        $bit[] = $time;
@@ -324,7 +326,7 @@ class Profiler {
                                        list( $method, $realtime ) = $info;
                                        $msg .= sprintf( "%d\t%.6f\t%s\n", $i, $realtime, $method );
                                }
-                               wfDebugLog( 'DBPerformance', $msg );
+                               $this->debugGroup( 'DBPerformance', $msg );
                        }
                        unset( $this->mDBTrxHoldingLocks[$name] );
                        unset( $this->mDBTrxMethodTimes[$name] );
@@ -720,6 +722,18 @@ class Profiler {
                }
        }
 
+       /**
+        * Add an entry in the debug log group
+        *
+        * @param string $group Group to send the message to
+        * @param string $s to output
+        */
+       function debugGroup( $group, $s ) {
+               if ( function_exists( 'wfDebugLog' ) ) {
+                       wfDebugLog( $group, $s );
+               }
+       }
+
        /**
         * Get the content type sent out to the client.
         * Used for profilers that output instead of store data.
index e81c6ec..5ecfc21 100644 (file)
@@ -90,7 +90,7 @@ class ProfilerMwprof extends Profiler {
                // Check for unbalanced profileIn / profileOut calls.
                // Bad entries are logged but not sent.
                if ( $inName !== $outName ) {
-                       wfDebugLog( 'ProfilerUnbalanced', json_encode( array( $inName, $outName ) ) );
+                       $this->debugGroup( 'ProfilerUnbalanced', json_encode( array( $inName, $outName ) ) );
                        return;
                }
 
index ee92c17..7d78e36 100644 (file)
@@ -102,17 +102,18 @@ class ProfilerSimple extends Profiler {
                list( $ofname, /* $ocount */, $ortime, $octime ) = array_pop( $this->mWorkStack );
 
                if ( !$ofname ) {
-                       $this->debug( "Profiling error: $functionname\n" );
+                       $this->debugGroup( 'profileerror', "Profiling error: $functionname" );
                } else {
                        if ( $functionname == 'close' ) {
-                               $message = "Profile section ended by close(): {$ofname}";
-                               $functionname = $ofname;
-                               $this->debug( "$message\n" );
-                               $this->mCollated[$message] = $this->errorEntry;
-                       }
-                       elseif ( $ofname != $functionname ) {
+                               if ( $ofname != '-total' ) {
+                                       $message = "Profile section ended by close(): {$ofname}";
+                                       $functionname = $ofname;
+                                       $this->debugGroup( 'profileerror', $message );
+                                       $this->mCollated[$message] = $this->errorEntry;
+                               }
+                       } elseif ( $ofname != $functionname ) {
                                $message = "Profiling error: in({$ofname}), out($functionname)";
-                               $this->debug( "$message\n" );
+                               $this->debugGroup( 'profileerror', $message );
                                $this->mCollated[$message] = $this->errorEntry;
                        }
                        $elapsedcpu = $this->getTime( 'cpu' ) - $octime;