From: Erik Bernhardson <ebernhardson@wikimedia.org>
Date: Mon, 11 Apr 2016 21:00:43 +0000 (-0700)
Subject: Track which web request created a job
X-Git-Tag: 1.31.0-rc.0~7300^2
X-Git-Url: http://git.cyclocoop.org/%28?a=commitdiff_plain;h=afc3b5a120a43a70c447ea15bfe85ba153a7ef10;p=lhc%2Fweb%2Fwiklou.git

Track which web request created a job

We currently push a request id into structured logging (monolog/
logstash) to allow seeing all logs that were triggered by the same
request. This extends that to pass the id through jobs so jobs triggered
by a web request also share the same id and can be tracked together.
This web request id will follow jobs both directly created by a request,
and jobs created by those jobs.

This should give us some more visibility when debugging into what
started a particular job, and if a large number of jobs blowing up the
job queue are somehow related.

Change-Id: Iedbd031e6e9bb18fd6f7b923c8c305102255ab4b
---

diff --git a/includes/WebRequest.php b/includes/WebRequest.php
index b18d59cb1d..b159f79526 100644
--- a/includes/WebRequest.php
+++ b/includes/WebRequest.php
@@ -43,6 +43,12 @@ class WebRequest {
 	 */
 	const GETHEADER_LIST = 1;
 
+	/**
+	 * The unique request ID.
+	 * @var string
+	 */
+	private static $reqId;
+
 	/**
 	 * Lazy-init response object
 	 * @var WebResponse
@@ -257,14 +263,23 @@ class WebRequest {
 	 * @since 1.27
 	 */
 	public static function getRequestId() {
-		static $reqId;
-
-		if ( !$reqId ) {
-			$reqId = isset( $_SERVER['UNIQUE_ID'] )
+		if ( !self::$reqId ) {
+			self::$reqId = isset( $_SERVER['UNIQUE_ID'] )
 				? $_SERVER['UNIQUE_ID'] : wfRandomString( 24 );
 		}
 
-		return $reqId;
+		return self::$reqId;
+	}
+
+	/**
+	 * Override the unique request ID. This is for sub-requests, such as jobs,
+	 * that wish to use the same id but are not part of the same execution context.
+	 *
+	 * @param string $id
+	 * @since 1.27
+	 */
+	public static function overrideRequestId( $id ) {
+		self::$reqId = $id;
 	}
 
 	/**
diff --git a/includes/jobqueue/Job.php b/includes/jobqueue/Job.php
index 9ccf6f8465..bbd0ddb5f8 100644
--- a/includes/jobqueue/Job.php
+++ b/includes/jobqueue/Job.php
@@ -92,6 +92,10 @@ abstract class Job implements IJobSpecification {
 
 		// expensive jobs may set this to true
 		$this->removeDuplicates = false;
+
+		if ( !isset( $this->params['requestId'] ) ) {
+			$this->params['requestId'] = WebRequest::getRequestId();
+		}
 	}
 
 	/**
@@ -152,6 +156,18 @@ abstract class Job implements IJobSpecification {
 			: null;
 	}
 
+	/**
+	 * @return string|null Id of the request that created this job. Follows
+	 *  jobs recursively, allowing to track the id of the request that started a
+	 *  job when jobs insert jobs which insert other jobs.
+	 * @since 1.27
+	 */
+	public function getRequestId() {
+		return isset( $this->params['requestId'] )
+			? $this->params['requestId']
+			: null;
+	}
+
 	/**
 	 * @return int|null UNIX timestamp of when the job was runnable, or null
 	 * @since 1.26
@@ -214,6 +230,8 @@ abstract class Job implements IJobSpecification {
 			unset( $info['params']['rootJobTimestamp'] );
 			// Likewise for jobs with different delay times
 			unset( $info['params']['jobReleaseTimestamp'] );
+			// Identical jobs from different requests should count as duplicates
+			unset( $info['params']['requestId'] );
 			// Queues pack and hash this array, so normalize the order
 			ksort( $info['params'] );
 		}
diff --git a/includes/jobqueue/JobRunner.php b/includes/jobqueue/JobRunner.php
index 0a0a7a2b79..a2f55b9e04 100644
--- a/includes/jobqueue/JobRunner.php
+++ b/includes/jobqueue/JobRunner.php
@@ -163,6 +163,8 @@ class JobRunner implements LoggerAwareInterface {
 				$popTime = time();
 				$jType = $job->getType();
 
+				WebRequest::overrideRequestId( $job->getRequestId() );
+
 				// Back off of certain jobs for a while (for throttling and for errors)
 				$ttw = $this->getBackoffTimeToWait( $job );
 				if ( $ttw > 0 ) {
diff --git a/tests/phpunit/includes/jobqueue/JobTest.php b/tests/phpunit/includes/jobqueue/JobTest.php
index 3c648f9bce..600a36ffe4 100644
--- a/tests/phpunit/includes/jobqueue/JobTest.php
+++ b/tests/phpunit/includes/jobqueue/JobTest.php
@@ -23,34 +23,36 @@ class JobTest extends MediaWikiTestCase {
 			->method( '__toString' )
 			->will( $this->returnValue( '{STRING_OBJ_VAL}' ) );
 
+		$requestId = 'requestId=' . WebRequest::getRequestId();
+
 		return [
 			[
 				$this->getMockJob( false ),
-				'someCommand '
+				'someCommand  ' . $requestId
 			],
 			[
 				$this->getMockJob( [ 'key' => 'val' ] ),
-				'someCommand  key=val'
+				'someCommand  key=val ' . $requestId
 			],
 			[
 				$this->getMockJob( [ 'key' => [ 'inkey' => 'inval' ] ] ),
-				'someCommand  key={"inkey":"inval"}'
+				'someCommand  key={"inkey":"inval"} ' . $requestId
 			],
 			[
 				$this->getMockJob( [ 'val1' ] ),
-				'someCommand  0=val1'
+				'someCommand  0=val1 ' . $requestId
 			],
 			[
 				$this->getMockJob( [ 'val1', 'val2' ] ),
-				'someCommand  0=val1 1=val2'
+				'someCommand  0=val1 1=val2 ' . $requestId
 			],
 			[
 				$this->getMockJob( [ new stdClass() ] ),
-				'someCommand  0=object(stdClass)'
+				'someCommand  0=object(stdClass) ' . $requestId
 			],
 			[
 				$this->getMockJob( [ $mockToStringObj ] ),
-				'someCommand  0={STRING_OBJ_VAL}'
+				'someCommand  0={STRING_OBJ_VAL} ' . $requestId
 			],
 			[
 				$this->getMockJob( [
@@ -73,7 +75,8 @@ class JobTest extends MediaWikiTestCase {
 				'rootJobSignature=45868e99bba89064e4483743ebb9b682ef95c1a7 ' .
 				'rootJobTimestamp=20160309110158 masterPos=' .
 				'{"file":"db1023-bin.001288","pos":"308257743","asOfTime":1457521464.3814} ' .
-				'triggeredRecursive=1'
+				'triggeredRecursive=1 ' .
+				$requestId
 			],
 		];
 	}