Thanks Ori!

FYI, the spikes in the graphs, are potentially due to T416567

For mw-web latency, the first jump seems to be ~30th of October.

Parsoid rollout has been posted by @Jgiannelos here T416567#11587120

SAL Log: https://sal.toolforge.org/production?p=1&q=&d=2025-10-30

(Posting here for transparancy, but mainly intended for @ArielGlenn.)

The first thing I tend to do after a change in reported latency, is to translate it to something absolute. It's easy to assume that something got slower, and that may be the case (a change in code, config, a shared resource like a database, the web servers through reduced CPU capacity, edits to a popular template that increased the cost of parsing most pages, etc). But, this is not a given.

For example, if we have fewer "fast" requests now, and other latency buckets contain the same number of requests, there is no latency regression, but most likely a change in traffic. Some requests no longer take place, thus shifting the average up, without changing anyone's experience and without increasing server load. It have been the result of an optimisation that removed redundant web requests from a workflow.

Likewise, if we have more "slow" requests than before, but the same amount in other buckets, there is also no latency regression. Requests did not move from faster to slower, but new traffic was added of a type that was likely already slow before and we have more of that type now. E.g. a slow endpoint that is called more often, thus shifting the average up, without regressins any specific experience or workflow. (Maybe. The new feature might be enabled within an existing experience where its addition might regress overall performance. But it could also be a standalone new thing.)

You can answer this through Rate, Histogram, and Heatmaps graphs, such as on the Grafana: Appserver RED k8s dashboard (select variables and date range first).

You can then use the same dashboard to start narrowing down what the affected traffic has in common (i.e. something more specific than "mw-web" servergroup) by looking for subsets (DC, http method) and related server groups (mw-api-ext, mw-api-int), and compare their average latencies over time, and try to rule out subsets that differ or rule in other servergroups that share the same change in latency.

There seems to be some amount of temporal causality with a more general pattern of a drop in hit rates for ParserCache - see https://grafana.wikimedia.org/goto/SBEpS9NDR?orgId=1 for details, and the attached graph for the TL;DR of what I mean:

I'm particularly puzzled by the fact that it seems to miss metadata completely. One of my fears is/was that it also kind of matches the timeline of "starting to push patches to introduce the post-processing cache", but a bug there would typically (normally!) have impacted the "unsafe" rate or the "miss" rate, not the "miss metadata" rate.

The drop in hit rates is explained as follows:

The nightly drop by 20% is T416567: Cache expirations (?) every UTC midnight and the cause described in T416616: Create new cache-friendly lua/parser function for "is today before X date" and "is today after X date"; and the decline on Parsoid since 11/25 is due to Fix cache expiration time for parsoid usage (1211138) -- Parsoid was completely ignoring wikitext-specified cache time reductions before that patch (T408741). This is a larger problem (partly described in T416567) where wikitext-initiated cache time reductions are probably having a disproportionate impact on cache hit rates and we should probably figure out better ways to do whatever folks are trying to do in the wikitext, possibly including selective update (T373258) of the portions of the page which are date-sensitive.

Some general decline of hit rate is due to T320668: Reduce TTL lowering effect and raise cache accuracy of CURRENT*/LOCAL* magic words deployed in March 2023 (parser: improve cache TTL accuracy for CURRENT*/LOCAL* magic words (569628)) for wikitext, but with followups on Nov 6 that affected Scribunto modules: T51803: Calculated Age of persons can become outdated until next cache purge/T389085: Frame::getTTL() appears to be completely unused, Remove use of Frame::setTTL/getTTL (1201829).

I'm not convinced that a 60% slowdown in backend request latency can be completely attributed to the decline in hit rates, but the reasons why hit rates declined is known (more or less).

To copy some context from a conversation elsewhere: one of the key things to notice in the cache hit rate graphs is that the cache hit rate starts getting sharper daily spikes due to T416567: Cache expirations (?) every UTC midnight/T416616 at the same time the cache rate drops by ~20%:

This is suggestive, but doesn't actually answer the original question posed by this task. In order to make the math work out correctly, we'd need to know the percentage of overall backend requests that are parsing related, and the relative latencies of cache hits and cache misses. It is plausible that these numbers work out to explain how a 20% decrease in cache hits creates an overall 60% latency increase... but that case hasn't actually been closed yet.

This diagram might also be interesting:
https://grafana.wikimedia.org/goto/Aqf_YrHvg?orgId=1

From what I understand, it looks like the sampled requests for profiling (thus the number of requests) for article views increased around the time we see the increase in latency.
This means that we get more requests bypassing caches.

On a day of Nov (the first that we have webrequest metrics) and on the same day in January.
Uncached desktop views increased by:

• ~2x on desktop
• ~1.7x on mobileweb
• ~1.2x on mobileapps

I only use webrequest queries for a day just because I don't know if we have actual stats that we can break it down in eg. grafana. Ideally its better to show we things evolve with time

Parsoid looks to be consuming basically all the CPU that mw-jobrunners have to offer:

The units of those graphs are seconds/second -- so every second, we're burning about 3-4 minutes of CPU time.

I'm not sure if a backlog on the jobrunners could cause a latency regression of this severity, though. But the CPU cost for mw-api-int and mw-api-ext have increased a fair bit in a relative sense as well.

I don't think Parsoid is the whole story though -- there are at least two other compounding factors here.

• Much greater than usual load from API scrapers in December
• Some much-longer-running but weird/concerning SELECT query & read load on the database masters (T416171) -- although I am still digging on that in between writing a KR proposal.

Those graphs are very interesting, because you're looking at enwiki, and Parsoid read views isn't deployed on enwiki yet. So these aren't read views. This is either refreshlinksjobs / linter, or apps/PCS. The increase also happens sharply on 11/27. We deployed a caching fix on 11/25, but I'm pretty sure that would be distinguishable from this spike on 11/27.

@Jgiannelos also noticed an gradual increase in index_view requests to the backend starting at the start of november.

In T416540#11592959, @CDanis wrote:

Parsoid looks to be consuming basically all the CPU that mw-jobrunners have to offer:

Maybe this would be useful or not: Flamegraph of CPU time on job runners:

• https://performance.wikimedia.org/arclamp/svgs/daily/2026-02-07.excimer.RunSingleJob.svgz
• https://performance.wikimedia.org/arclamp/svgs/daily/2026-02-07.excimer.RunSingleJob.reversed.svgz

The latency trend for this past ~week is even worse:

In T416540#11592285, @Jgiannelos wrote:

This diagram might also be interesting:
https://grafana.wikimedia.org/goto/Aqf_YrHvg?orgId=1

From what I understand, it looks like the sampled requests for profiling (thus the number of requests) for article views increased around the time we see the increase in latency. This means that we get more requests bypassing caches. […]

More requests could imply more purges or higher average latency, but it does not have to.

If the added requests do not specifically target unpopular or uncached pages, then CDN caching, request coalescing, and ParserCache, should leave average latency unchanged or even lower it, if the excess traffic has a narrower distribution than the baseline (hitting warm ParserCache/Memc/APCU/DB caches). For example, a small scale CDN-cachebusting flood on a specific article lower average latency. (Of course, at higher scales, such flood may sature k8s/mysql capacity and slow things down, but this period doesn't show that so I'm assuming relatively small scale changes for now, something where we're slower on the CPU rather than slower due to I/O saturation).

I'm looking mainly at Oct 10 - Dec 12 as the range of the main rise (per the graphs in task description)

I don't see any increase in time spent in Parsoid. Looking at the new "One component" dashboard, which zooms in on mediawiki-entrypoint-profiling dash, which aggregates Flame graphs: We actually see a slight drop in percentage of time spent in index.php?action=view:

What I see instead, is 10 pc point increase on of legacy Parser time spent:

This was a bit harder to plot, because the folders and namespaces were renamed around Oct 30 (e.g. change 1200040 and related changes), and the dropdown menu only lists current values, not historical ones. The above was ad-hoc edited to include the previous name.

In my opinion, there may be more than one contributing factor has led to this, each in different ways. Moreover, as we've found out the hard way, traffic patterns have been changing rapidly since last year, with the most notable one being increase in uncached requests.

Strictly speaking, from a capacity perspective (not taking into account information such as % of uncached requestss or overall traffic increase), our mw-on-k8s deployments were resized last October, based on some very good math @Scott_French put together.

Running estimate_mw_replicas week by week in an attempt to see the trend:

One of the reasons we have ended up here could be that we need more capacity. I would suggest we consider adding so, until we figure out what else might no be right or has room for improvements.

I have a scenario that might be interesting where there is a combination of parsoid, rest API and CDN purges cascading effect that I am trying to reproduce. I believe that its worth checking what happens when:

• We get cache misses because of the TTL enforced from magic words
• The requests don't come from read views but from API calls who hit parsoid eventually regardless of rollout of read view in production
  • even though read views in enwiki are using legacy parser, api calls use parsoid
• CDN is purged/evicted for those requests in a faster rate
• Backend load is creating backpressure to read views

What is unclear in this scenario is whether reparses occurring in the cluster can impact web backend latency. I am not entirely sure in which part of the infrastructure we run reparses and if its a job in the jobqueue or part of req/response.

A slightly OT question: When I see Cache expiry: 1807, is it possible to identify the reason for it? I suspect it comes from the MIN_DEADLINE_TTL (30*60=1800) in CoreMagicVariables.php. The method I have found so far is bisecting a page's source code, and inspect the NewPP report by previewing.

An instance I found on zhwiki (template) is caused by invocation of {{#time:}}, resulting from gerrit #1201838.

This will be fixed by T416616: Create new cache-friendly lua/parser function for "is today before X date" and "is today after X date".

Mentioned in SAL (#wikimedia-operations) [2026-02-18T00:58:21Z] <Krinkle> Edit Module:Date on various wikis in attempt to mitigate T416616, T416540. Details at https://phabricator.wikimedia.org/T416616#11625838.

In T416540#11614737, @Bewfip wrote:

A slightly OT question: When I see Cache expiry: 1807, is it possible to identify the reason for it? I suspect it comes from the MIN_DEADLINE_TTL (30*60=1800) in CoreMagicVariables.php. The method I have found so far is bisecting a page's source code, and inspect the NewPP report by previewing.

An instance I found on zhwiki (template) is caused by invocation of {{#time:}}, resulting from gerrit #1201838.

When https://gerrit.wikimedia.org/r/c/mediawiki/core/+/1240461 and https://gerrit.wikimedia.org/r/c/mediawiki/extensions/Scribunto/+/1241053 land, you'll see the template, parser function or module that reduced the page's TTL in the page's NewPP report.

The fix to Module:Date on enwiki last week, improved logged-in pageview response times by 30%. Grafana: Navigation Timing logged-in (Feb 2026):

Logged-in pageview performance is interesting to me because so far we only established:

• average appserver latency increase. Comments above and T302623#11502725 confirm there was not an increase in CDN misses, and so this likely affects otherwise-unchanged/existing traffic, as opposed to new traffic to slow URLs bringing the average down. However, the distribution means that fast responses are still common, and so it is not clear how "common" this slowdown is among readers.
• ParserCache misses increasing, but those could largely be from JobQueue/API requests for ParserOutput, and from CDN cache misses to warm up caches for logged-out readers, which are overall rare given that CDN caching isn't impacted or reduced by this issue.

Logged-in pageview response times regressed by 40% beteen October and December.

Grafana: Navigation Timing logged-in (Oct 2025) dashboard:

This makes sense in retrospect. ParserCache had expiries of 30 minutes, the CDN cache retained its normal 24-hour expiry. It did mean that those CDN requests now more often parse instead of re-use a still-valid ParserCache entry, but it's hard to quantify that for logged-out readers at our scale. For logged-in users on the other hand, that 30-minute expiry is effective immediately, and so means it is very likely for logged-in users to constantly wait for a re-parse on miss.

It's interesting that this had such a big effect on logged-in pageview response times; the change in parsercache hit rate is visible but more modest:

We still have the big daily spikes, which are probably going to be exacerbated by Parser: Raise minimum TTL from 30 min to 'next midnight' in miser mode (1240300) before being fixed more properly by T416616: Create new cache-friendly lua/parser function for "is today before X date" and "is today after X date".

Change #1240300 had a related patch set uploaded (by C. Scott Ananian; author: C. Scott Ananian):

[mediawiki/core@master] Parser: Raise minimum TTL from 30 min to 'next midnight' in miser mode

https://gerrit.wikimedia.org/r/1240300

Change #1240300 merged by jenkins-bot:

[mediawiki/core@master] Parser: Raise minimum TTL from 30 min to 'next midnight' in miser mode

https://gerrit.wikimedia.org/r/1240300

Change #1250013 had a related patch set uploaded (by C. Scott Ananian; author: C. Scott Ananian):

[mediawiki/core@wmf/1.46.0-wmf.18] Parser: Raise minimum TTL from 30 min to 'next midnight' in miser mode

https://gerrit.wikimedia.org/r/1250013

Change #1250013 abandoned by C. Scott Ananian:

[mediawiki/core@wmf/1.46.0-wmf.18] Parser: Raise minimum TTL from 30 min to 'next midnight' in miser mode

Reason:

Meant to backport this to wmf.19, not wmf.18

https://gerrit.wikimedia.org/r/1250013

Change #1250015 had a related patch set uploaded (by C. Scott Ananian; author: C. Scott Ananian):

[mediawiki/core@wmf/1.46.0-wmf.19] Parser: Raise minimum TTL from 30 min to 'next midnight' in miser mode

https://gerrit.wikimedia.org/r/1250015

Change #1250015 merged by jenkins-bot:

[mediawiki/core@wmf/1.46.0-wmf.19] Parser: Raise minimum TTL from 30 min to 'next midnight' in miser mode

https://gerrit.wikimedia.org/r/1250015

Mentioned in SAL (#wikimedia-operations) [2026-03-10T20:25:45Z] <jforrester@deploy2002> Started scap sync-world: Backport for [[gerrit:1240012|Enable personal main menu to all users in Minerva Neue skin (T413912)]], [[gerrit:1250007|Enables legacy processing in ParserOutputPostCacheTransform when cached (T372592)]], [[gerrit:1250015|Parser: Raise minimum TTL from 30 min to 'next midnight' in miser mode (T416616 T416540 T419439)]]

Mentioned in SAL (#wikimedia-operations) [2026-03-10T20:27:51Z] <jforrester@deploy2002> jforrester, cscott, bwang: Backport for [[gerrit:1240012|Enable personal main menu to all users in Minerva Neue skin (T413912)]], [[gerrit:1250007|Enables legacy processing in ParserOutputPostCacheTransform when cached (T372592)]], [[gerrit:1250015|Parser: Raise minimum TTL from 30 min to 'next midnight' in miser mode (T416616 T416540 T419439)]] synced to the testservers (see https://wikitech.wi

Mentioned in SAL (#wikimedia-operations) [2026-03-10T20:38:43Z] <jforrester@deploy2002> Finished scap sync-world: Backport for [[gerrit:1240012|Enable personal main menu to all users in Minerva Neue skin (T413912)]], [[gerrit:1250007|Enables legacy processing in ParserOutputPostCacheTransform when cached (T372592)]], [[gerrit:1250015|Parser: Raise minimum TTL from 30 min to 'next midnight' in miser mode (T416616 T416540 T419439)]] (duration: 12m 58s)

Hey folks, are there any more actionables left for this task?

In T416540#11953922, @jijiki wrote:

Hey folks, are there any more actionables left for this task?

This task was last commented on in February, when the regression was not yet fully reversed. The latest changes in subtask T416616: Create new cache-friendly lua/parser function for "is today before X date" and "is today after X date" went live in early April and that seems to have done the trick.

Comparing the same graphs as in the original task description, in T302623#11730913, and today. Range represent daily seasonality (other smaller variations I've averaged out).

From the task description:

[…]
As mentioned in T302623, looking at Grafana: Backend Pageview Timing dashboard:

Mar-Apr 2025 (Grafana)
Oct-Dec 2025
Mar-May 2026

And the mw-web RED dashboard

Codfw:

Eqiad:

One could say the mw-web p95 is still elevated, and the Backend Pageview Timing % latency <=250ms isn't quite as high. But that could have any number of reasons at this point. We can probably better work on those by looking for optimizations in general, than to further look for a regression that may or may not have been introduced during Oct-Dec 2025.