API action=parsoid-batch not available on Graphite
Open, LowPublic


We regularly have to investigate API issues related to the MediaWiki extension ParsoidBatchAPI. It defines an API module parsoid-batch which has at least the sub actions

  • parse || preprocess
  • imageinfo

However that never generates timing metrics in statsd and thus we we are blindness as to how many and how long those queries takes.

Given the recent API overloads we have seen, we definitely need metrics to be collected. They will be accessible via: https://grafana-admin.wikimedia.org/dashboard/db/api-requests and we might want to include them in the EventBus/Change-Propagation/RestBase boards since they seem to be the main source of parsoid-batch calls.

The lame workaround to investigate is to look at the api log bucket on Fluorine which luckily has the timing informations. Example for action taking 10s to 99s:

$ tail -F /a/mw-log/api.log|grep -E 'T=.?....ms action=parsoid-batch'|cut -d\  -f5,14,13
srwiki T=3358ms action=parsoid-batch
enwiki T=1170ms action=parsoid-batch
commonswiki T=1010ms action=parsoid-batch
commonswiki T=1010ms action=parsoid-batch
srwiki T=4653ms action=parsoid-batch
cywiki T=1213ms action=parsoid-batch
enwiki T=1425ms action=parsoid-batch
enwiki T=1008ms action=parsoid-batch

Inside MediaWiki API, the statsd reporting is handled by ApiMain::executeActionWithErrorHandling() however they are only reported when issued from a POST request and the module has been flagged as being writing. Summary of code:

function executeActionWithErrorHandling {
    $runTime = microtime( true ) - $t;

    if ( $this->mModule->isWriteMode() && $this->getRequest()->wasPosted() ) {
                    'api.' . $this->mModule->getModuleName() . '.executeTiming', 1000 * $runTime

action=parsoid-batch are POST but do not have isWriteMode() and hence are not logged.

Looks like the MediaWiki ApiMain would need a new method to force reporting statsd which we can then use in ParsoidBatchApi to force reporting.

hashar created this task.Dec 9 2016, 1:29 PM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptDec 9 2016, 1:29 PM
Legoktm added a subscriber: Legoktm.Dec 9 2016, 9:24 PM

I don't think this is going to be that useful....the numbers will be all over the place, we really just need to look at the slow-parse.log better.

Ottomata added a subscriber: Ottomata.

I don't think there are any ops action items here, so I'm removing the tag.

hashar triaged this task as Low priority.Jun 16 2017, 10:59 AM