MediaWiki  master
JobRunner.php
Go to the documentation of this file.
1 <?php
24 use Liuggio\StatsdClient\Factory\StatsdDataFactoryInterface;
28 use Psr\Log\LoggerInterface;
34 use Wikimedia\ScopedCallback;
35 
42 class JobRunner {
43 
47  public const CONSTRUCTOR_OPTIONS = [
48  MainConfigNames::JobBackoffThrottling,
49  MainConfigNames::JobClasses,
50  MainConfigNames::JobSerialCommitThreshold,
51  MainConfigNames::MaxJobDBWriteDuration,
52  MainConfigNames::TrxProfilerLimits,
53  ];
54 
56  private $options;
57 
59  private $lbFactory;
60 
62  private $jobQueueGroup;
63 
65  private $readOnlyMode;
66 
68  private $linkCache;
69 
71  private $stats;
72 
74  private $debug;
75 
77  private $logger;
78 
80  private const MAX_ALLOWED_LAG = 3;
82  private const SYNC_TIMEOUT = self::MAX_ALLOWED_LAG;
84  private const LAG_CHECK_PERIOD = 1.0;
86  private const ERROR_BACKOFF_TTL = 1;
88  private const READONLY_BACKOFF_TTL = 30;
89 
93  public function setDebugHandler( $debug ) {
94  $this->debug = $debug;
95  }
96 
107  public function __construct(
108  ServiceOptions $serviceOptions,
109  ILBFactory $lbFactory,
110  JobQueueGroup $jobQueueGroup,
111  ReadOnlyMode $readOnlyMode,
112  LinkCache $linkCache,
113  StatsdDataFactoryInterface $statsdDataFactory,
114  LoggerInterface $logger
115  ) {
116  $serviceOptions->assertRequiredOptions( self::CONSTRUCTOR_OPTIONS );
117  $this->options = $serviceOptions;
118  $this->lbFactory = $lbFactory;
119  $this->jobQueueGroup = $jobQueueGroup;
120  $this->readOnlyMode = $readOnlyMode;
121  $this->linkCache = $linkCache;
122  $this->stats = $statsdDataFactory;
123  $this->logger = $logger;
124  }
125 
151  public function run( array $options ) {
152  $type = $options['type'] ?? false;
153  $maxJobs = $options['maxJobs'] ?? false;
154  $maxTime = $options['maxTime'] ?? false;
155  $throttle = $options['throttle'] ?? true;
156 
157  $jobClasses = $this->options->get( MainConfigNames::JobClasses );
158  $profilerLimits = $this->options->get( MainConfigNames::TrxProfilerLimits );
159 
160  $response = [ 'jobs' => [], 'reached' => 'none-ready' ];
161 
162  if ( $type !== false && !isset( $jobClasses[$type] ) ) {
163  // Invalid job type specified
164  $response['reached'] = 'none-possible';
165  return $response;
166  }
167 
168  if ( $this->readOnlyMode->isReadOnly() ) {
169  // Any jobs popped off the queue might fail to run and thus might end up lost
170  $response['reached'] = 'read-only';
171  return $response;
172  }
173 
174  [ , $maxLag ] = $this->lbFactory->getMainLB()->getMaxLag();
175  if ( $maxLag >= self::MAX_ALLOWED_LAG ) {
176  // DB lag is already too high; caller can immediately try other wikis if applicable
177  $response['reached'] = 'replica-lag-limit';
178  return $response;
179  }
180 
181  // Narrow DB query expectations for this HTTP request
182  $this->lbFactory->getTransactionProfiler()
183  ->setExpectations( $profilerLimits['JobRunner'], __METHOD__ );
184 
185  // Error out if an explicit DB transaction round is somehow active
186  if ( $this->lbFactory->hasTransactionRound() ) {
187  throw new LogicException( __METHOD__ . ' called with an active transaction round.' );
188  }
189 
190  // Some jobs types should not run until a certain timestamp
191  $backoffs = []; // map of (type => UNIX expiry)
192  $backoffDeltas = []; // map of (type => seconds)
193  $wait = 'wait'; // block to read backoffs the first time
194 
195  $loopStartTime = microtime( true );
196  $jobsPopped = 0;
197  $timeMsTotal = 0;
198  $lastSyncTime = 1; // initialize "last sync check timestamp" to "ages ago"
199  // Keep popping and running jobs until there are no more...
200  do {
201  // Sync the persistent backoffs with concurrent runners
202  $backoffs = $this->syncBackoffDeltas( $backoffs, $backoffDeltas, $wait );
203  $backoffKeys = $throttle ? array_keys( $backoffs ) : [];
204  $wait = 'nowait'; // less important now
205 
206  if ( $type === false ) {
207  // Treat the default job type queues as a single queue and pop off a job
208  $job = $this->jobQueueGroup
210  } else {
211  // Pop off a job from the specified job type queue unless the execution of
212  // that type of job is currently rate-limited by the back-off list
213  $job = in_array( $type, $backoffKeys ) ? false : $this->jobQueueGroup->pop( $type );
214  }
215 
216  if ( $job ) {
217  ++$jobsPopped;
218  $jType = $job->getType();
219 
220  // Back off of certain jobs for a while (for throttling and for errors)
221  $ttw = $this->getBackoffTimeToWait( $job );
222  if ( $ttw > 0 ) {
223  // Always add the delta for other runners in case the time running the
224  // job negated the backoff for each individually but not collectively.
225  $backoffDeltas[$jType] = ( $backoffDeltas[$jType] ?? 0 ) + $ttw;
226  $backoffs = $this->syncBackoffDeltas( $backoffs, $backoffDeltas, $wait );
227  }
228 
229  $info = $this->executeJob( $job );
230 
231  // Mark completed or "one shot only" jobs as resolved
232  if ( $info['status'] !== false || !$job->allowRetries() ) {
233  $this->jobQueueGroup->ack( $job );
234  }
235 
236  // Back off of certain jobs for a while (for throttling and for errors)
237  if ( $info['status'] === false && mt_rand( 0, 49 ) == 0 ) {
238  $ttw = max( $ttw, $this->getErrorBackoffTTL( $info['caught'] ) );
239  $backoffDeltas[$jType] = ( $backoffDeltas[$jType] ?? 0 ) + $ttw;
240  }
241 
242  $response['jobs'][] = [
243  'type' => $jType,
244  'status' => ( $info['status'] === false ) ? 'failed' : 'ok',
245  'error' => $info['error'],
246  'time' => $info['timeMs']
247  ];
248  $timeMsTotal += $info['timeMs'];
249 
250  // Break out if we hit the job count or wall time limits
251  if ( $maxJobs && $jobsPopped >= $maxJobs ) {
252  $response['reached'] = 'job-limit';
253  break;
254  } elseif ( $maxTime && ( microtime( true ) - $loopStartTime ) > $maxTime ) {
255  $response['reached'] = 'time-limit';
256  break;
257  }
258 
259  // Stop if we caught a DBConnectionError. In theory it would be
260  // possible to explicitly reconnect, but the present behaviour
261  // is to just throw more exceptions every time something database-
262  // related is attempted.
263  if ( in_array( DBConnectionError::class, $info['caught'], true ) ) {
264  $response['reached'] = 'exception';
265  break;
266  }
267 
268  // Don't let any of the main DB replica DBs get backed up.
269  // This only waits for so long before exiting and letting
270  // other wikis in the farm (on different masters) get a chance.
271  $timePassed = microtime( true ) - $lastSyncTime;
272  if ( $timePassed >= self::LAG_CHECK_PERIOD || $timePassed < 0 ) {
273  $opts = [ 'ifWritesSince' => $lastSyncTime, 'timeout' => self::SYNC_TIMEOUT ];
274  if ( !$this->lbFactory->waitForReplication( $opts ) ) {
275  $response['reached'] = 'replica-lag-limit';
276  break;
277  }
278  $lastSyncTime = microtime( true );
279  }
280 
281  // Abort if nearing OOM to avoid erroring out in the middle of a job
282  if ( !$this->checkMemoryOK() ) {
283  $response['reached'] = 'memory-limit';
284  break;
285  }
286  }
287  } while ( $job );
288 
289  // Sync the persistent backoffs for the next runJobs.php pass
290  if ( $backoffDeltas ) {
291  $this->syncBackoffDeltas( $backoffs, $backoffDeltas, 'wait' );
292  }
293 
294  $response['backoffs'] = $backoffs;
295  $response['elapsed'] = $timeMsTotal;
296 
297  return $response;
298  }
299 
318  public function executeJob( RunnableJob $job ) {
319  $telemetry = Telemetry::getInstance();
320  $oldRequestId = $telemetry->getRequestId();
321 
322  if ( $job->getRequestId() !== null ) {
323  // Temporarily inherit the original ID of the web request that spawned this job
324  $telemetry->overrideRequestId( $job->getRequestId() );
325  } else {
326  // TODO: do we need to regenerate if job doesn't have the request id?
327  // If JobRunner was called with X-Request-ID header, regeneration will generate the
328  // same value
329  $telemetry->regenerateRequestId();
330  }
331  // Use an appropriate timeout to balance lag avoidance and job progress
332  $oldTimeout = $this->lbFactory->setDefaultReplicationWaitTimeout( self::SYNC_TIMEOUT );
333  try {
334  return $this->doExecuteJob( $job );
335  } finally {
336  $this->lbFactory->setDefaultReplicationWaitTimeout( $oldTimeout );
337  $telemetry->overrideRequestId( $oldRequestId );
338  }
339  }
340 
349  private function doExecuteJob( RunnableJob $job ) {
350  $jType = $job->getType();
351  $msg = $job->toString() . " STARTING";
352  $this->logger->debug( $msg, [ 'job_type' => $job->getType() ] );
353  $this->debugCallback( $msg );
354 
355  // Clear out title cache data from prior snapshots
356  // (e.g. from before JobRunner was invoked in this process)
357  $this->linkCache->clear();
358 
359  // Run the job...
360  $caught = [];
361  $rssStart = $this->getMaxRssKb();
362  $jobStartTime = microtime( true );
363  try {
364  $fnameTrxOwner = get_class( $job ) . '::run'; // give run() outer scope
365  // Flush any pending changes left over from an implicit transaction round
366  if ( $job->hasExecutionFlag( $job::JOB_NO_EXPLICIT_TRX_ROUND ) ) {
367  $this->lbFactory->commitPrimaryChanges( $fnameTrxOwner ); // new implicit round
368  } else {
369  $this->lbFactory->beginPrimaryChanges( $fnameTrxOwner ); // new explicit round
370  }
371  // Clear any stale REPEATABLE-READ snapshots from replica DB connections
372  $this->lbFactory->flushReplicaSnapshots( $fnameTrxOwner );
373  $status = $job->run();
374  $error = $job->getLastError();
375  // Commit all pending changes from this job
376  $this->commitPrimaryChanges( $job, $fnameTrxOwner );
377  // Run any deferred update tasks; doUpdates() manages transactions itself
379  } catch ( Throwable $e ) {
381  $status = false;
382  $error = get_class( $e ) . ': ' . $e->getMessage() . ' in '
383  . $e->getFile() . ' on line ' . $e->getLine();
384  $caught[] = get_class( $e );
385  }
386  // Always attempt to call teardown(), even if Job throws exception
387  try {
388  $job->tearDown( $status );
389  } catch ( Throwable $e ) {
391  }
392 
393  $timeMs = intval( ( microtime( true ) - $jobStartTime ) * 1000 );
394  $rssEnd = $this->getMaxRssKb();
395 
396  // Record how long jobs wait before getting popped
397  $readyTs = $job->getReadyTimestamp();
398  if ( $readyTs ) {
399  $pickupDelay = max( 0, $jobStartTime - $readyTs );
400  $this->stats->timing( 'jobqueue.pickup_delay.all', 1000 * $pickupDelay );
401  $this->stats->timing( "jobqueue.pickup_delay.$jType", 1000 * $pickupDelay );
402  }
403  // Record root job age for jobs being run
404  $rootTimestamp = $job->getRootJobParams()['rootJobTimestamp'];
405  if ( $rootTimestamp ) {
406  $age = max( 0, $jobStartTime - (int)wfTimestamp( TS_UNIX, $rootTimestamp ) );
407  $this->stats->timing( "jobqueue.pickup_root_age.$jType", 1000 * $age );
408  }
409  // Track the execution time for jobs
410  $this->stats->timing( "jobqueue.run.$jType", $timeMs );
411  // Track RSS increases for jobs (in case of memory leaks)
412  if ( $rssStart && $rssEnd ) {
413  $this->stats->updateCount( "jobqueue.rss_delta.$jType", $rssEnd - $rssStart );
414  }
415 
416  if ( $status === false ) {
417  $msg = $job->toString() . " t={job_duration} error={job_error}";
418  $this->logger->error( $msg, [
419  'job_type' => $job->getType(),
420  'job_duration' => $timeMs,
421  'job_error' => $error,
422  ] );
423 
424  $msg = $job->toString() . " t=$timeMs error={$error}";
425  $this->debugCallback( $msg );
426  } else {
427  $msg = $job->toString() . " t={job_duration} good";
428  $this->logger->info( $msg, [
429  'job_type' => $job->getType(),
430  'job_duration' => $timeMs,
431  ] );
432 
433  $msg = $job->toString() . " t=$timeMs good";
434  $this->debugCallback( $msg );
435  }
436 
437  return [
438  'status' => $status,
439  'error' => $error,
440  'caught' => $caught,
441  'timeMs' => $timeMs
442  ];
443  }
444 
449  private function getErrorBackoffTTL( array $caught ) {
450  return in_array( DBReadOnlyError::class, $caught )
451  ? self::READONLY_BACKOFF_TTL
452  : self::ERROR_BACKOFF_TTL;
453  }
454 
458  private function getMaxRssKb() {
459  $info = getrusage( 0 /* RUSAGE_SELF */ );
460  // see https://linux.die.net/man/2/getrusage
461  return isset( $info['ru_maxrss'] ) ? (int)$info['ru_maxrss'] : null;
462  }
463 
469  private function getBackoffTimeToWait( RunnableJob $job ) {
470  $throttling = $this->options->get( MainConfigNames::JobBackoffThrottling );
471 
472  if ( !isset( $throttling[$job->getType()] ) || $job instanceof DuplicateJob ) {
473  return 0; // not throttled
474  }
475 
476  $itemsPerSecond = $throttling[$job->getType()];
477  if ( $itemsPerSecond <= 0 ) {
478  return 0; // not throttled
479  }
480 
481  $seconds = 0;
482  if ( $job->workItemCount() > 0 ) {
483  $exactSeconds = $job->workItemCount() / $itemsPerSecond;
484  // use randomized rounding
485  $seconds = floor( $exactSeconds );
486  $remainder = $exactSeconds - $seconds;
487  $seconds += ( mt_rand() / mt_getrandmax() < $remainder ) ? 1 : 0;
488  }
489 
490  return (int)$seconds;
491  }
492 
501  private function loadBackoffs( array $backoffs, $mode = 'wait' ) {
502  $file = wfTempDir() . '/mw-runJobs-backoffs.json';
503  if ( is_file( $file ) ) {
504  $noblock = ( $mode === 'nowait' ) ? LOCK_NB : 0;
505  $handle = fopen( $file, 'rb' );
506  if ( !flock( $handle, LOCK_SH | $noblock ) ) {
507  fclose( $handle );
508  return $backoffs; // don't wait on lock
509  }
510  $content = stream_get_contents( $handle );
511  flock( $handle, LOCK_UN );
512  fclose( $handle );
513  $ctime = microtime( true );
514  $cBackoffs = json_decode( $content, true ) ?: [];
515  foreach ( $cBackoffs as $type => $timestamp ) {
516  if ( $timestamp < $ctime ) {
517  unset( $cBackoffs[$type] );
518  }
519  }
520  } else {
521  $cBackoffs = [];
522  }
523 
524  return $cBackoffs;
525  }
526 
538  private function syncBackoffDeltas( array $backoffs, array &$deltas, $mode = 'wait' ) {
539  if ( !$deltas ) {
540  return $this->loadBackoffs( $backoffs, $mode );
541  }
542 
543  $noblock = ( $mode === 'nowait' ) ? LOCK_NB : 0;
544  $file = wfTempDir() . '/mw-runJobs-backoffs.json';
545  $handle = fopen( $file, 'wb+' );
546  if ( !flock( $handle, LOCK_EX | $noblock ) ) {
547  fclose( $handle );
548  return $backoffs; // don't wait on lock
549  }
550  $ctime = microtime( true );
551  $content = stream_get_contents( $handle );
552  $cBackoffs = json_decode( $content, true ) ?: [];
553  foreach ( $deltas as $type => $seconds ) {
554  $cBackoffs[$type] = isset( $cBackoffs[$type] ) && $cBackoffs[$type] >= $ctime
555  ? $cBackoffs[$type] + $seconds
556  : $ctime + $seconds;
557  }
558  foreach ( $cBackoffs as $type => $timestamp ) {
559  if ( $timestamp < $ctime ) {
560  unset( $cBackoffs[$type] );
561  }
562  }
563  ftruncate( $handle, 0 );
564  fwrite( $handle, json_encode( $cBackoffs ) );
565  flock( $handle, LOCK_UN );
566  fclose( $handle );
567 
568  $deltas = [];
569 
570  return $cBackoffs;
571  }
572 
578  private function checkMemoryOK() {
579  static $maxBytes = null;
580  if ( $maxBytes === null ) {
581  $m = [];
582  if ( preg_match( '!^(\d+)(k|m|g|)$!i', ini_get( 'memory_limit' ), $m ) ) {
583  [ , $num, $unit ] = $m;
584  $conv = [ 'g' => 1073741824, 'm' => 1048576, 'k' => 1024, '' => 1 ];
585  $maxBytes = (int)$num * $conv[strtolower( $unit )];
586  } else {
587  $maxBytes = 0;
588  }
589  }
590  $usedBytes = memory_get_usage();
591  if ( $maxBytes && $usedBytes >= 0.95 * $maxBytes ) {
592  $msg = "Detected excessive memory usage ({used_bytes}/{max_bytes}).";
593  $this->logger->error( $msg, [
594  'used_bytes' => $usedBytes,
595  'max_bytes' => $maxBytes,
596  ] );
597 
598  $msg = "Detected excessive memory usage ($usedBytes/$maxBytes).";
599  $this->debugCallback( $msg );
600 
601  return false;
602  }
603 
604  return true;
605  }
606 
611  private function debugCallback( $msg ) {
612  if ( $this->debug ) {
613  call_user_func_array( $this->debug, [ wfTimestamp( TS_DB ) . " $msg\n" ] );
614  }
615  }
616 
627  private function commitPrimaryChanges( RunnableJob $job, $fnameTrxOwner ) {
628  $syncThreshold = $this->options->get( MainConfigNames::JobSerialCommitThreshold );
629 
630  $time = false;
631  $lb = $this->lbFactory->getMainLB();
632  if ( $syncThreshold !== false && $lb->hasStreamingReplicaServers() ) {
633  // Generally, there is one primary connection to the local DB
634  $dbwSerial = $lb->getAnyOpenConnection( $lb->getWriterIndex() );
635  // We need natively blocking fast locks
636  if ( $dbwSerial && $dbwSerial->namedLocksEnqueue() ) {
637  $time = $dbwSerial->pendingWriteQueryDuration( $dbwSerial::ESTIMATE_DB_APPLY );
638  if ( $time < $syncThreshold ) {
639  $dbwSerial = false;
640  }
641  } else {
642  $dbwSerial = false;
643  }
644  } else {
645  // There are no replica DBs or writes are all to foreign DB (we don't handle that)
646  $dbwSerial = false;
647  }
648 
649  if ( !$dbwSerial ) {
650  $this->lbFactory->commitPrimaryChanges(
651  $fnameTrxOwner,
652  // Abort if any transaction was too big
653  $this->options->get( MainConfigNames::MaxJobDBWriteDuration )
654  );
655 
656  return;
657  }
658 
659  $ms = intval( 1000 * $time );
660 
661  $msg = $job->toString() . " COMMIT ENQUEUED [{job_commit_write_ms}ms of writes]";
662  $this->logger->info( $msg, [
663  'job_type' => $job->getType(),
664  'job_commit_write_ms' => $ms,
665  ] );
666 
667  $msg = $job->toString() . " COMMIT ENQUEUED [{$ms}ms of writes]";
668  $this->debugCallback( $msg );
669 
670  // Wait for an exclusive lock to commit
671  if ( !$dbwSerial->lock( 'jobrunner-serial-commit', $fnameTrxOwner, 30 ) ) {
672  // This will trigger a rollback in the main loop
673  throw new DBError( $dbwSerial, "Timed out waiting on commit queue." );
674  }
675  $unlocker = new ScopedCallback( static function () use ( $dbwSerial, $fnameTrxOwner ) {
676  $dbwSerial->unlock( 'jobrunner-serial-commit', $fnameTrxOwner );
677  } );
678 
679  // Wait for the replica DBs to catch up
680  $pos = $lb->getPrimaryPos();
681  if ( $pos ) {
682  $lb->waitForAll( $pos );
683  }
684 
685  // Actually commit the DB primary changes
686  $this->lbFactory->commitPrimaryChanges(
687  $fnameTrxOwner,
688  // Abort if any transaction was too big
689  $this->options->get( MainConfigNames::MaxJobDBWriteDuration )
690  );
691  ScopedCallback::consume( $unlocker );
692  }
693 }
wfTempDir()
Tries to get the system directory for temporary files.
wfTimestamp( $outputtype=TS_UNIX, $ts=0)
Get a timestamp string in one of various formats.
static doUpdates( $stage=self::ALL)
Consume and execute all pending updates.
No-op job that does nothing.
Handle enqueueing of background jobs.
Job queue runner utility methods.
Definition: JobRunner.php:42
setDebugHandler( $debug)
Definition: JobRunner.php:93
run(array $options)
Run jobs of the specified number/type for the specified time.
Definition: JobRunner.php:151
const CONSTRUCTOR_OPTIONS
Definition: JobRunner.php:47
executeJob(RunnableJob $job)
Run a specific job in a manner appropriate for mass use by job dispatchers.
Definition: JobRunner.php:318
__construct(ServiceOptions $serviceOptions, ILBFactory $lbFactory, JobQueueGroup $jobQueueGroup, ReadOnlyMode $readOnlyMode, LinkCache $linkCache, StatsdDataFactoryInterface $statsdDataFactory, LoggerInterface $logger)
Definition: JobRunner.php:107
Cache for article titles (prefixed DB keys) and ids linked from one source.
Definition: LinkCache.php:45
static rollbackPrimaryChangesAndLog(Throwable $e, $catcher=self::CAUGHT_BY_OTHER)
Roll back any open database transactions and log the stack trace of the throwable.
static logException(Throwable $e, $catcher=self::CAUGHT_BY_OTHER, $extraData=[])
Log a throwable to the exception log (if enabled).
A class for passing options to services.
assertRequiredOptions(array $expectedKeys)
Assert that the list of options provided in this instance exactly match $expectedKeys,...
Service for handling telemetry data.
Definition: Telemetry.php:29
A class containing constants representing the names of configuration variables.
Database error base class.
Definition: DBError.php:37
Determine whether a site is currently in read-only mode.
Job that has a run() method and metadata accessors for JobQueue::pop() and JobQueue::ack()
Definition: RunnableJob.php:37
Manager of ILoadBalancer objects and, indirectly, IDatabase connections.
Definition: ILBFactory.php:46
if(count( $args)< 1) $job
$content
Definition: router.php:76
if(PHP_SAPI !='cli-server') if(!isset( $_SERVER['SCRIPT_FILENAME'])) $file
Item class for a filearchive table row.
Definition: router.php:42