Mentioned in SAL (#wikimedia-operations) [2019-08-22T14:37:19Z] <_joe_> restarting php-fpm on mw1348 to observe the effect on the slowdown, T231011

First smoking gun is in all the intervals I controlled the offender was parsoid-batch with quite large requests. I'm trying to gathering more cases to create a better statistics.

Mentioned in SAL (#wikimedia-operations) [2019-08-29T08:11:21Z] <_joe_> disabling zend GC on mw1347, testing an hypothesis for T231011

Looks like this is back since yesterday:

Logs show many requests that take a long time to finish are of type action=parsoid-batch on euwiki version 1.34.0-wmf.23

euwiki heavily uses wikidata, it might be related to wb_terms table. Does it correlate with spikes in https://grafana.wikimedia.org/d/000000548/wikibase-wb_terms?refresh=30s&orgId=1&panelId=2&fullscreen&from=now-24h&to=now ?

Related: T229407: Spikes in DB traffic and rows/s reads when reading from new terms store

@Ladsgroup might be on the correct track here. The spikes neatly coincide with the WD bot updates.

In T231011#5663421, @mobrovac wrote:

@Ladsgroup might be on the correct track here. The spikes neatly coincide with the WD bot updates.

The patch that actually smooths this just got merged. Planning to backport it now.

Mentioned in SAL (#wikimedia-operations) [2019-11-14T16:04:20Z] <ladsgroup@deploy1001> Synchronized php-1.35.0-wmf.5/extensions/Wikibase: [[gerrit:550828|Put a layer of APC cache on top of reading wb_terms in SqlEntityInfoBuilder]] (T231011 T229407 T236681), Try II (duration: 00m 56s)

@Theklan might be interested in watching this task too.

Last days I have been heavily merging some templates, and it may be related.

@Theklan We suspect it is something on the production side since we have noticed this behaviour in the past. Moreover, this is not the only wiki where templates are changed, but it manages to standout in our investigations, which shouldn't happen. Nevertheless, thanks for letting us know :)

I think it's in the ~35mins "schedule" now, but other than that, it's still present https://grafana.wikimedia.org/d/RIA1lzDZk/application-servers-red-dashboard?orgId=1&var-datasource=eqiad%20prometheus%2Fops&var-cluster=api_appserver&var-method=GET&var-code=200&from=1573809235233&to=1573845235233

Ok! Now there's nothing special happening at euwiki and there are not new merges happening, so it should be another thing.

Anybody knows if this is still an issue nowadays?

It seems the pattern has stopped.

I can still see it on Nov 30th:

https://grafana.wikimedia.org/d/RIA1lzDZk/application-servers-red-dashboard?orgId=1&var-datasource=eqiad%20prometheus%2Fops&var-cluster=api_appserver&var-method=GET&var-code=200&from=1575072000000&to=1575158399000&fullscreen&panelId=9

but after that, clicking through the first 2 weeks of December day by day, i can't see the "half hour spike pattern" anymore.

example December 8th:

https://grafana.wikimedia.org/d/RIA1lzDZk/application-servers-red-dashboard?orgId=1&var-datasource=eqiad%20prometheus%2Fops&var-cluster=api_appserver&var-method=GET&var-code=200&from=1573171200000&to=1573257599000&fullscreen&panelId=9