TLDR: Those with shell access at WMF can now run maintenance scripts on mwdebug hosts, and
use the *--profiler=text* option to produce a report detailing how long the script spent
in each MediaWiki component, class, and function.
== *What* ==
The MediaWiki platform at WMF consists of broadly four different deployments: app servers,
api_app servers, job runners, and maint servers (diagram
<https://wikitech.wikimedia.org/wiki/MediaWiki_at_WMF#/media/File:MediaWiki_infrastructure_2022.png>).
Each can be thought of as its own service for a specific purpose, composed of a subset of
components from the MediaWiki codebase with fast local access to each. The largest of
these is the appservers cluster, which is served by 150 servers of dedicated hardware
across the two application data centers
<https://wikitech.wikimedia.org/wiki/Data_centers>, and is responsible for
responding to index.php (i.e. page views) and load.php (CSS, JS, and localisation via
ResourceLoader).
Today, we focus on the smallest of these: mwmaint servers
<https://wikitech.wikimedia.org/wiki/Maintenance_server>. This is backed by two
heavy-duty servers, one in each data center, that autonomously run essential tasks at a
predefined schedule (i.e. not in direct response to a user action). Each of these ~50
different tasks is implemented as a MediaWiki maintenance script. Important examples
include: sending email notifications (Echo extension), timely pruning of sensitive PII
(CheckUser extension), computing mentee and link recommendation data (GrowthExperiments),
and reclaiming disk space for expired caches (core/ParserCache).
== *Why ==*
We have detailed debug performance profiling in production for web requests via the
WikimediaDebug extension, and we have detailed profiling in local development for both web
requests and maintenance scripts (Docker recipe
<https://www.mediawiki.org/wiki/MediaWiki-Docker/Configuration_recipes/Profiling>).
What was missing is a way to profile maintenance scripts in production. This is important
as maintenance scripts tend take many minutes or hours to process vast amounts of
production data. While generally easy to debug locally for functional analysis, the
performance bottlenecks individual teams care about are likely specific to the size of the
data and the performance of other production components.
Thanks also to Ahmon Dancy (RelEng), Giuseppe Lavagetto (SRE), and Aaron Schulz
(Performance Team) for making this work possible, and Niklas Laxström (LangEng) for coming
up with the idea.
== *What's New* ==
Documentation:
https://wikitech.wikimedia.org/wiki/WikimediaDebug#Plaintext_CLI_profile
To profile a Maintenance script, run the script from the shell with *mwscript* as you
normally would, but instead of connecting your terminal to mwmaint1002.eqiad.wmnet,
connect to one of the *mwdebug* hosts (such as mwdebug1001.eqiad.wmnet). Then pass the
*--profiler=text* option to generate a report with the performance analysis, which will be
printed after the task is finished. Like so:
$ mwscript showSiteStats.php --wiki=nlwiki
--profiler=text
Number of articles: 2122688
Number of users : 1276507
<!--
100.00% 114.964 1 - main()
…
22.42% 25.776 1 - ShowSiteStats::execute
16.61% 19.096 2 - Wikimedia\Rdbms\LoadBalancer::getServerConnection
4.80% 5.522 1 - Maintenance::shutdown
4.41% 5.065 1 - Wikimedia\Rdbms\Database::initConnection
3.07% 3.530 1 - DeferredUpdates::doUpdates
2.66% 3.061 1 - Wikimedia\Rdbms\Database::select
2.38% 2.739 1 - Wikimedia\Rdbms\Database::query
1.95% 2.240 1 - section.SELECT * FROM `site_stats` LIMIT N
1.48% 1.700 1 - Wikimedia\Rdbms\DatabaseMysqli::mysqlConnect
…
-->
== *A peak behind the curtain* ==
Read on if you'd like to learn what hurdles we had to overcome for this to
"simply" work in production, like it did for local development. The journey
started when Niklas (WMF LangEng) proposed the idea at
https://phabricator.wikimedia.org/T253547.
*Firstly*, the profiler engine. In 2019 (blogpost
<https://techblog.wikimedia.org/2019/12/16/wikimediadebug-v2-is-here/>), after we
migrated from HHVM to PHP 7, we had to look for a new profiler engine for backend
performance. We adopted the open source php-tideways package, and this has powered our
browser-facing profiler since. Naturally, this was already installed on the mwdebug
servers for that purpose. However, the package, and the accompanying *rdtsc* setting, were
only set for php-fpm (web server), it was not yet enabled for php-cli (command-line).
*Secondly*, the Profiler component in MediaWiki core had gotten out of sync with the needs
of the Skin and Maintenance components. Over years of refactoring and more parts of each
component gaining an active owner, the parts that lacked an owner eroded and stopped
working, including the integration between these components. We decided to take active
ownership over the remaining parts of MediaWiki-Core-Profiler and fix the disconnect. The
meta work for that included identifying and re-triaging open issues under a new
#mediawiki-core-profiler
<https://phabricator.wikimedia.org/tag/mediawiki-core-profiler/> tag, automating
discovery to our team inbox via Phabricator Herald rule, enlisting on Maintainers
<https://www.mediawiki.org/wiki/Developers/Maintainers>, and automatic discovery of
changesets to our code review dashboard.
<https://gerrit.wikimedia.org/r/p/wikimedia/+/dashboard/teams:performance>
The "output" step of the profiler was originally the responsibility of a
wfLogProfilingData function that both webpages (Skin) and CLI (Maintenance) called upon
toward the end of the response. After this function became deprecated, and further
refactoring in the Skin and Maintenance component took on (some of) its responsibilities
directly, the "output" step got lost. Adding this back in was non-trivial
because by now, the code in question had gained an unintentional dependency on the
WebRequest object, which is not valid in a CLI context. The code in question was
simplified and decoupled in change 725152
<https://gerrit.wikimedia.org/r/c/mediawiki/core/+/725152/> and change 725440
<https://gerrit.wikimedia.org/r/c/mediawiki/core/+/725440>, when then made it
possible to add back the "output" step in change 838884
<https://gerrit.wikimedia.org/r/c/mediawiki/core/+/838884/>. We also removed various
options
<https://gerrit.wikimedia.org/r/q/message:profiler+project:mediawiki/core+branch:master+is:merged>
(such as CMDLINE_CALLBACK <https://phabricator.wikimedia.org/T305422>) that we
choose to not support and maintain going forward (undocumented, unused, broken, or without
known use case after research).
*Thirdly*, in parallel with our work above, another team refactored MediaWiki's
SettingsLoader and MaintenanceRunner components. The Profiler dates back more than a
decade and still relied on the fact that settings could be changed by CLI script options
such as *--profiler=text*. The new SettingsLoader and the refactored MaintenanceRunner
streamlined the order of operations during process startup, which had the side effect of
initialising the profiler slightly earlier than it used to. This meant it would initialise
before the --profiler=text option was applied, and thus the profiler that was initialised
was unconditionally the "null" profiler. This did not produce an error since
that is a valid configuration, the configuration of effectively all traffic besides ad-hoc
debugging. I remedied this
<https://gerrit.wikimedia.org/r/c/mediawiki/core/+/875396/> by recognising the CLI
option as its own setting (separate from the main one), and passing it down via dependency
injection. Thus not relying on the subtle order of operations.
The Profiler component is now significantly leaner than it was before, and its
requirements are either explicitly coded through dependency injection requirements, or
simplified/refactored such that they do not place requirements on other components.
*Fourthly*, the wmf-config repository, where we control how and when MediaWiki Profiler
can be enabled, had been changed by us the year before, to feature a new sampling profiler
to produce detailed flame graphs over production traffic (blog post
<https://techblog.wikimedia.org/2021/03/03/profiling-php-in-production-at-scale/>).
I realised that this configuration assumed a web context. Another tweak over there
<https://gerrit.wikimedia.org/r/c/operations/mediawiki-config/+/874419/> made this
safe to enabled in CLI/Maintenance script contexts.
*Fifthly*, in order to actually enable the wmf-config/Profiler code in CLI, we needed to
set the same *php.ini* configuration for php-cli as we already did years earlier for
php-fpm (web server). In doing so, we ran into the problem that one server in particular
(deploy1002, from where the MediaWiki train runs via Scap) had two mutually exclusive
copies of the MediaWiki deployment (/srv/mediawiki and /srv/mediawiki-staging). This meant
that preloading a profiler for either of them from php-cli would break the other. I
identified this long-standing technical debt to Ahmon Dancy (RelEng), who then went on a
whole journey of his own to radically simplify our deployment servers to not have these
two separate installations (T329857 <https://phabricator.wikimedia.org/T329857>).
*Finally*, with a one-line change in Puppet
<https://gerrit.wikimedia.org/r/c/operations/puppet/+/910882/> config, the CLI
profiler is now enabled in production (Thanks Giuseppe Lavagetto, from SRE). All in all,
this made the different parts of codebase, and different parts of our platform less
divergent and more unified than before.
Thanks again to Aaron Schulz, Ahmon Dancy, Giuseppe Lavagetto, and Niklas Laxström for
their help!
--
Timo Tijhof,
Principal Engineer,
Performance Team,
Wikimedia Foundation.