Deprecate wfLogProfilingData(), improve statsd/profiling docs

* Document that Maintenance::shutdown is the CLI equivalent of
  MediaWiki::restInPeace.

* Centrally document in the emitStats method why we flush stats
  regularly, and clarify that these OOM concerns are specific to
  CLI processes there. That isn't to say it could never happen on a
  web request, but all our early flush handling (even DB trx hooks)
  are explicitly limited to command-line mode today and always have
  been.

* Ref T253547. It is now clear why --profiler=text doesn't work on
  the CLI (it is missing the non-external profiler output handling),
  which I'll fix in a follow-up.

* Ref T292269. The WebRequest-dependency in Profiler is now much more
  clearly problematic. Previously this was masked by wfLogProfilingData
  effectively silencing the warning on the CLI without it being so
  obviously wrong. I'll fix that in a follow-up.

* Ref T292253. All this is already post-send, and flame graphs confirm
  that we don't have any calls to emitBufferedStatsdData nor
  StatsdClient::send apart from the post-send one via restInPeace.

Bug: T253547
Bug: T292269
Bug: T292253
Change-Id: If78c37046cf8651c7a8d6690e01d38c3ca29d8d8
This commit is contained in:
Timo Tijhof 2021-10-01 00:01:06 +01:00
parent 42a24c3e98
commit c49a45f6bf
3 changed files with 53 additions and 9 deletions

View file

@ -1133,10 +1133,18 @@ class MediaWiki {
);
// Do any deferred jobs; preferring to run them now if a client will not wait on them
DeferredUpdates::doUpdates( 'run' );
DeferredUpdates::doUpdates();
// Log profiling data, e.g. in the database or UDP
wfLogProfilingData();
// Handle external profiler outputs.
// Any embedded profiler outputs were already processed in outputResponsePayload().
$profiler = Profiler::instance();
$profiler->setContext( $this->context );
$profiler->logData();
self::emitBufferedStatsdData(
MediaWikiServices::getInstance()->getStatsdDataFactory(),
$this->config
);
// Commit and close up!
$lbFactory->commitPrimaryChanges( __METHOD__ );
@ -1148,6 +1156,25 @@ class MediaWiki {
/**
* Send out any buffered statsd data according to sampling rules
*
* For web requests, this is called once by MediaWiki::restInPeace(),
* which is post-send (after the response is sent to the client).
*
* For maintenance scripts, especially long-running CLI scripts, it is called
* more often, to avoid OOM, since we buffer stats (T181385), based on the
* following heuristics:
*
* - Long-running scripts that involve database writes often use transactions
* to commit chunks of work. We flush from IDatabase::setTransactionListener,
* as wired up by MWLBFactory::applyGlobalState.
*
* - Long-running scripts that involve database writes but don't need any
* transactions will still periodically wait for replication to be
* graceful to the databases. We flush from ILBFactory::setWaitForReplicationListener
* as wired up by MWLBFactory::applyGlobalState.
*
* - Any other long-running scripts will probably report progress to stdout
* in some way. We also flush from Maintenance::output().
*
* @param IBufferingStatsdDataFactory $stats
* @param Config $config
* @throws ConfigException

View file

@ -422,7 +422,7 @@ abstract class MWLBFactory {
__METHOD__,
static function () use ( $stats, $config ) {
DeferredUpdates::tryOpportunisticExecute( 'run' );
// Try to periodically flush buffered metrics to avoid OOMs
// Flush stats periodically in long-running CLI scripts to avoid OOM (T181385)
MediaWiki::emitBufferedStatsdData( $stats, $config );
}
);
@ -434,7 +434,7 @@ abstract class MWLBFactory {
if ( $trigger === IDatabase::TRIGGER_COMMIT ) {
DeferredUpdates::tryOpportunisticExecute( 'run' );
}
// Try to periodically flush buffered metrics to avoid OOMs
// Flush stats periodically in long-running CLI scripts to avoid OOM (T181385)
MediaWiki::emitBufferedStatsdData( $stats, $config );
}
);

View file

@ -435,7 +435,7 @@ abstract class Maintenance {
protected function output( $out, $channel = null ) {
// This is sometimes called very early, before Setup.php is included.
if ( class_exists( MediaWikiServices::class ) ) {
// Try to periodically flush buffered metrics to avoid OOMs
// Flush stats periodically in long-running CLI scripts to avoid OOM (T181385)
$stats = MediaWikiServices::getInstance()->getStatsdDataFactory();
if ( $stats->getDataCount() > 1000 ) {
MediaWiki::emitBufferedStatsdData( $stats, $this->getConfig() );
@ -1229,7 +1229,12 @@ abstract class Maintenance {
}
/**
* Call before shutdown to run any deferred updates
* Call before exiting CLI process for the last DB commit, and flush
* any remaining buffers and other deferred work.
*
* Equivalent to MediaWiki::restInPeace which handles shutdown for web requests,
* and should perform the same operations and in the same order.
*
* @since 1.36
*/
public function shutdown() {
@ -1241,11 +1246,23 @@ abstract class Maintenance {
) {
$lbFactory = MediaWikiServices::getInstance()->getDBLoadBalancerFactory();
$lbFactory->commitPrimaryChanges( get_class( $this ) );
// @TODO: make less assumptions about deferred updates being coupled to the DB
DeferredUpdates::doUpdates();
}
wfLogProfilingData();
// Handle external profiler outputs
// FIXME: Handle embedded outputs as well, such as ProfilerOutputText (T253547)
$profiler = Profiler::instance();
// FIXME: Make Profiler not need a WebRequest (T292269)
// This set/get call silences the Profiler::getContext warning.
// This is "safe" so long as Profiler.php only uses this to call WebRequest::getElapsedTime().
$profiler->setContext( RequestContext::getMain() );
$profiler->logData();
MediaWiki::emitBufferedStatsdData(
MediaWikiServices::getInstance()->getStatsdDataFactory(),
$this->getConfig()
);
if ( $lbFactory ) {
$lbFactory->commitPrimaryChanges( 'doMaintenance' );