Add an API log
authorTim Starling <tstarling@wikimedia.org>
Wed, 19 Sep 2012 10:07:48 +0000 (20:07 +1000)
committerGerrit Code Review <gerrit@wikimedia.org>
Mon, 24 Sep 2012 21:22:09 +0000 (21:22 +0000)
During incident response, it was not possible to tell what API modules
were being requested and by whom, since the action parameter is often
posted. This change logs the API parameters whether they are posted or
sent in the query string.

I did try to get the API parameters from the module, but that turns out
to be difficult. Modules create submodules (generators, page sets) as
local variables, which are created in a procedural style and destroyed
before logging is done, so there is no easy way to query them for
parameter lists after execution completes.

In ApiOptionsTest, use a real ApiMain object like all the other API test
cases, rather than a mock object. Otherwise the test fails.

Change-Id: Idc786007fe61811d1874f29b5ce4762dd97b1847

includes/api/ApiBase.php
includes/api/ApiMain.php
tests/phpunit/includes/api/ApiOptionsTest.php

index 875a381..1513e7d 100644 (file)
@@ -929,9 +929,9 @@ abstract class ApiBase extends ContextSource {
                                ApiBase::dieDebug( __METHOD__, "Boolean param $encParamName's default is set to '$default'. Boolean parameters must default to false." );
                        }
 
-                       $value = $this->getRequest()->getCheck( $encParamName );
+                       $value = $this->getMain()->getCheck( $encParamName );
                } else {
-                       $value = $this->getRequest()->getVal( $encParamName, $default );
+                       $value = $this->getMain()->getVal( $encParamName, $default );
 
                        if ( isset( $value ) && $type == 'namespace' ) {
                                $type = MWNamespace::getValidNamespaces();
index 35febd9..bfc4933 100644 (file)
@@ -135,6 +135,7 @@ class ApiMain extends ApiBase {
 
        private $mCacheMode = 'private';
        private $mCacheControl = array();
+       private $mParamsUsed = array();
 
        /**
         * Constructs an instance of ApiMain that utilizes the module and format specified by $request.
@@ -168,7 +169,7 @@ class ApiMain extends ApiBase {
                        // Remove all modules other than login
                        global $wgUser;
 
-                       if ( $this->getRequest()->getVal( 'callback' ) !== null ) {
+                       if ( $this->getVal( 'callback' ) !== null ) {
                                // JSON callback allows cross-site reads.
                                // For safety, strip user credentials.
                                wfDebug( "API: stripping user credentials for JSON callback\n" );
@@ -365,6 +366,7 @@ class ApiMain extends ApiBase {
                // clear the output buffer and print just the error information
                ob_start();
 
+               $t = microtime( true );
                try {
                        $this->executeAction();
                } catch ( Exception $e ) {
@@ -401,6 +403,9 @@ class ApiMain extends ApiBase {
                        $this->printResult( true );
                }
 
+               // Log the request whether or not there was an error
+               $this->logRequest( microtime( true ) - $t);
+
                // Send cache headers after any code which might generate an error, to
                // avoid sending public cache headers for errors.
                $this->sendCacheHeaders();
@@ -816,6 +821,7 @@ class ApiMain extends ApiBase {
                $module->profileOut();
 
                if ( !$this->mInternalMode ) {
+
                        //append Debug information
                        MWDebug::appendDebugInfoToApiResult( $this->getContext(), $this->getResult() );
 
@@ -824,6 +830,73 @@ class ApiMain extends ApiBase {
                }
        }
 
+       /**
+        * Log the preceding request
+        * @param $time Time in seconds
+        */
+       protected function logRequest( $time ) {
+               $request = $this->getRequest();
+               $milliseconds = $time === null ? '?' : round( $time * 1000 );
+               $s = 'API' . 
+                       ' ' . $request->getMethod() .
+                       ' ' . wfUrlencode( str_replace( ' ', '_', $this->getUser()->getName() ) ) .
+                       ' ' . $request->getIP() .
+                       ' T=' . $milliseconds .'ms';
+               foreach ( $this->getParamsUsed() as $name ) {
+                       $value = $request->getVal( $name );
+                       if ( $value === null ) {
+                               continue;
+                       }
+                       $s .= ' ' . $name . '=';
+                       if ( strlen( $value ) > 256 ) {
+                               $encValue = $this->encodeRequestLogValue( substr( $value, 0, 256 ) );
+                               $s .= $encValue . '[...]';
+                       } else {
+                               $s .= $this->encodeRequestLogValue( $value );
+                       }
+               }
+               $s .= "\n";
+               wfDebugLog( 'api', $s, false );
+       }
+
+       /**
+        * Encode a value in a format suitable for a space-separated log line.
+        */
+       protected function encodeRequestLogValue( $s ) {
+               static $table;
+               if ( !$table ) {
+                       $chars = ';@$!*(),/:';
+                       for ( $i = 0; $i < strlen( $chars ); $i++ ) {
+                               $table[ rawurlencode( $chars[$i] ) ] = $chars[$i];
+                       }
+               }
+               return strtr( rawurlencode( $s ), $table );
+       }
+
+       /**
+        * Get the request parameters used in the course of the preceding execute() request
+        */
+       protected function getParamsUsed() {
+               return array_keys( $this->mParamsUsed );
+       }
+
+       /**
+        * Get a request value, and register the fact that it was used, for logging.
+        */
+       public function getVal( $name, $default = null ) {
+               $this->mParamsUsed[$name] = true;
+               return $this->getRequest()->getVal( $name, $default );
+       }
+
+       /**
+        * Get a boolean request value, and register the fact that the parameter
+        * was used, for logging.
+        */
+       public function getCheck( $name ) {
+               $this->mParamsUsed[$name] = true;
+               return $this->getRequest()->getCheck( $name );          
+       }
+
        /**
         * Print results using the current printer
         *
index 8acdc1c..d54d7df 100644 (file)
@@ -5,7 +5,7 @@
  */
 class ApiOptionsTest extends MediaWikiLangTestCase {
 
-       private $mTested, $mApiMainMock, $mUserMock, $mContext, $mSession;
+       private $mTested, $mUserMock, $mContext, $mSession;
 
        private static $Success = array( 'options' => 'success' );
 
@@ -16,27 +16,16 @@ class ApiOptionsTest extends MediaWikiLangTestCase {
                        ->disableOriginalConstructor()
                        ->getMock();
 
-               $this->mApiMainMock = $this->getMockBuilder( 'ApiBase' )
-                       ->disableOriginalConstructor()
-                       ->getMock();
-
                // Create a new context
                $this->mContext = new DerivativeContext( new RequestContext() );
                $this->mContext->setUser( $this->mUserMock );
 
-               $this->mApiMainMock->expects( $this->any() )
-                       ->method( 'getContext' )
-                       ->will( $this->returnValue( $this->mContext ) );
-
-               $this->mApiMainMock->expects( $this->any() )
-                       ->method( 'getResult' )
-                       ->will( $this->returnValue( new ApiResult( $this->mApiMainMock ) ) );
-
+               $main = new ApiMain( $this->mContext );
 
                // Empty session
                $this->mSession = array();
 
-               $this->mTested = new ApiOptions( $this->mApiMainMock, 'options' );
+               $this->mTested = new ApiOptions( $main, 'options' );
        }
 
        private function getSampleRequest( $custom = array() ) {