Provide a unique request identifier
authorOri Livneh <ori@wikimedia.org>
Fri, 25 Mar 2016 01:43:23 +0000 (18:43 -0700)
committerBryanDavis <bdavis@wikimedia.org>
Fri, 25 Mar 2016 16:09:05 +0000 (16:09 +0000)
When MediaWiki encounters an unhandled exception, the error message it produces
includes a randomly-generated token, which allows the exception details to be
looked up in the error logs. This is useful but narrow: would it not be useful
to have the ability to retrieve all log records associated with a particular
request, rather than just exception details? (Hint: yes.)

So: introduce the notion of a request-global unique ID, retrievable via
WebRequest::getRequestId(). When MediaWiki is behind Apache + mod_unique_id
(which provides the same facility) or some other software which sets a
UNIQUE_ID envvar, the value of that envvar is used as the request ID.
Otherwise, it is a randomly-generated 24-character string.

The request ID supplants exception-specific IDs; MWExceptionHandler::getLogId()
is deprecated, accordingly. The request ID is also added as an annotation to
all Monolog-processed log records, and is exposed client-side as 'wgRequestId'.
This allows developers to associate a page view with log records even when the
page view does not result in an unhandled exception. (For the WMF, I also
intend to add it as an annotation to profiling data).

The request ID is not a tracking token; it does not persist, and it is
associated with a backend request, not with a particular user or a particular
session. Like the data in the NewPP report, the request ID is designed to be
cacheable, so that if, for example, a developer notices something weird in the
HTML, s/he can associate the output with a backend request regardless of
whether the response was served from the cache or directly from the backend.

Some prior art:
* https://httpd.apache.org/docs/2.4/mod/mod_unique_id.html
* http://api.rubyonrails.org/classes/ActionDispatch/RequestId.html
* https://github.com/dabapps/django-log-request-id
* https://packagist.org/packages/php-middleware/request-id
* https://github.com/rhyselsmore/flask-request-id

Change-Id: Iaf90c20c330e0470b9b98627a0228cadefd301d1

RELEASE-NOTES-1.27
includes/OutputPage.php
includes/WebRequest.php
includes/api/ApiMain.php
includes/debug/logger/monolog/WikiProcessor.php
includes/exception/MWException.php
includes/exception/MWExceptionHandler.php

index ac19d39..915b93b 100644 (file)
@@ -175,6 +175,12 @@ HHVM 3.1.
   be a good idea, but will log out all current sessions.
 * $wgEventRelayerConfig was added, for managing PubSub event relay configuration,
   specifically for reliable CDN url purges.
+* Requests have unique IDs, equal to the UNIQUE_ID environment variable (when
+  MediaWiki is behind Apache+mod_unique_id or something similar) or a randomly-
+  generated 24-character string. This request ID is used to annotate log records
+  and error messages. It is available client-side via mw.config.get( 'wgRequestId' ).
+  The request ID supplants exception IDs. Accordingly, MWExceptionHandler::getLogId()
+  is deprecated.
 
 === External library changes in 1.27 ===
 
index 0c3d609..3c0dc18 100644 (file)
@@ -3210,6 +3210,7 @@ class OutputPage extends ContextSource {
                        'wgMonthNamesShort' => $lang->getMonthAbbreviationsArray(),
                        'wgRelevantPageName' => $relevantTitle->getPrefixedDBkey(),
                        'wgRelevantArticleId' => $relevantTitle->getArticleID(),
+                       'wgRequestId' => WebRequest::getRequestId(),
                ];
 
                if ( $user->isLoggedIn() ) {
index 812a320..f4b4871 100644 (file)
@@ -246,6 +246,25 @@ class WebRequest {
                return microtime( true ) - $this->requestTime;
        }
 
+       /**
+        * Get the unique request ID.
+        * This is either the value of the UNIQUE_ID envvar (if present) or a
+        * randomly-generated 24-character string.
+        *
+        * @return string
+        * @since 1.27
+        */
+       public static function getRequestId() {
+               static $reqId;
+
+               if ( !$reqId ) {
+                       $reqId = isset( $_SERVER['UNIQUE_ID'] )
+                               ? $_SERVER['UNIQUE_ID'] : wfRandomString( 24 );
+               }
+
+               return $reqId;
+       }
+
        /**
         * Get the current URL protocol (http or https)
         * @return string
index 63b79ac..5566d31 100644 (file)
@@ -871,7 +871,7 @@ class ApiMain extends ApiBase {
 
                        $errMessage = [
                                'code' => 'internal_api_error_' . get_class( $e ),
-                               'info' => '[' . MWExceptionHandler::getLogId( $e ) . '] ' . $info,
+                               'info' => '[' . WebRequest::getRequestId() . '] ' . $info,
                        ];
                }
                return $errMessage;
index 7f60f2e..e3c048d 100644 (file)
@@ -21,7 +21,8 @@
 namespace MediaWiki\Logger\Monolog;
 
 /**
- * Injects `wfHostname()`, `wfWikiID()` and `$wgVersion` in all records.
+ * Annotate log records with request-global metadata, such as the hostname,
+ * wiki / request ID, and MediaWiki version.
  *
  * @since 1.25
  * @author Bryan Davis <bd808@wikimedia.org>
@@ -41,6 +42,7 @@ class WikiProcessor {
                                'host' => wfHostname(),
                                'wiki' => wfWikiID(),
                                'mwversion' => $wgVersion,
+                               'reqId' => WebRequest::getRequestId(),
                        ]
                );
                return $record;
index e1d7e6c..bebd915 100644 (file)
@@ -141,7 +141,7 @@ class MWException extends Exception {
                        nl2br( htmlspecialchars( MWExceptionHandler::getRedactedTraceAsString( $this ) ) ) .
                        "</p>\n";
                } else {
-                       $logId = MWExceptionHandler::getLogId( $this );
+                       $logId = WebRequest::getRequestId();
                        $type = get_class( $this );
                        return "<div class=\"errorbox\">" .
                        '[' . $logId . '] ' .
index b71f92c..63adc29 100644 (file)
@@ -445,14 +445,13 @@ TXT;
         * $wgShowExceptionDetails is set to false), to the entry in the debug log.
         *
         * @since 1.22
+        * @deprecated since 1.27: Exception IDs are synonymous with request IDs.
         * @param Exception|Throwable $e
         * @return string
         */
        public static function getLogId( $e ) {
-               if ( !isset( $e->_mwLogId ) ) {
-                       $e->_mwLogId = wfRandomString( 8 );
-               }
-               return $e->_mwLogId;
+               wfDeprecated( __METHOD__, '1.27' );
+               return WebRequest::getRequestId();
        }
 
        /**
@@ -478,7 +477,7 @@ TXT;
         * @return string
         */
        public static function getLogMessage( $e ) {
-               $id = self::getLogId( $e );
+               $id = WebRequest::getRequestId();
                $type = get_class( $e );
                $file = $e->getFile();
                $line = $e->getLine();
@@ -489,9 +488,9 @@ TXT;
        }
 
        public static function getPublicLogMessage( Exception $e ) {
-               $logId = self::getLogId( $e );
+               $reqId = WebRequest::getRequestId();
                $type = get_class( $e );
-               return '[' . $logId . '] '
+               return '[' . $reqId . '] '
                        . gmdate( 'Y-m-d H:i:s' ) . ': '
                        . 'Fatal exception of type ' . $type;
        }
@@ -509,7 +508,7 @@ TXT;
        public static function getLogContext( $e ) {
                return [
                        'exception' => $e,
-                       'exception_id' => static::getLogId( $e ),
+                       'exception_id' => WebRequest::getRequestId(),
                ];
        }
 
@@ -527,7 +526,7 @@ TXT;
        public static function getStructuredExceptionData( $e ) {
                global $wgLogExceptionBacktrace;
                $data = [
-                       'id' => self::getLogId( $e ),
+                       'id' => WebRequest::getRequestId(),
                        'type' => get_class( $e ),
                        'file' => $e->getFile(),
                        'line' => $e->getLine(),