Page MenuHomePhabricator

Wikibase Lua: addStatementUsage seems unjustifiably expensive
Closed, ResolvedPublic

Description

From the Lua profile of https://de.wikivoyage.org/wiki/Halle_(Saale) (see html source code):

Lua Profile:
    Scribunto_LuaSandboxCallback::callParserFunction                1960 ms       45.6%
    Scribunto_LuaSandboxCallback::getEntity                          600 ms       14.0%
    Scribunto_LuaSandboxCallback::addStatementUsage                  540 ms       12.6%
    Scribunto_LuaSandboxCallback::gsub                               280 ms        6.5%
    Scribunto_LuaSandboxCallback::getEntityStatements                200 ms        4.7%
    Scribunto_LuaSandboxCallback::addSiteLinksUsage                  120 ms        2.8%
    ?                                                                100 ms        2.3%
    Scribunto_LuaSandboxCallback::incrementStatsKey                   80 ms        1.9%
    init <Modul:CountryData/Geography>                                60 ms        1.4%
    recursiveClone <mwInit.lua:41>                                    40 ms        0.9%
    [others]                                                         320 ms        7.4%

On top of "the usual suspects" like getEntity (which are expected to be heavy, given they load the actual entities), addStatementUsage also seems to be fairly expensive.

Things to consider:

  • Only calling addStatementUsage once for each statement (cache in mw.wikibase.entity) IMPORTANT : Make sure the cache is not shared between titles/ parser runs)
  • Make the PHP implementation faster: Don't update the ParserOutput's extension data unless absolutely needed (not sure this saves enough)

Event Timeline

Restricted Application added a subscriber: Aklapper. · View Herald Transcript

That page has almost 700 entity usages:

MariaDB [dewikivoyage_p]> SELECT COUNT(*) FROM wbc_entity_usage WHERE eu_page_id = 3899;
+----------+
| COUNT(*) |
+----------+
|      698 |
+----------+
1 row in set (0.01 sec)

I just purged the page and it is gone now:

Lua Profile:
    Scribunto_LuaSandboxCallback::getEntityStatements               2240 ms       41.6%
    Scribunto_LuaSandboxCallback::callParserFunction                1920 ms       35.7%
    Scribunto_LuaSandboxCallback::getSiteLinkPageName                280 ms        5.2%
    Scribunto_LuaSandboxCallback::gsub                               120 ms        2.2%
    Scribunto_LuaSandboxCallback::incrementStatsKey                  100 ms        1.9%
    Scribunto_LuaSandboxCallback::entityExists                       100 ms        1.9%
    init <Modul:Languages>                                            80 ms        1.5%
    Scribunto_LuaSandboxCallback::anchorEncode                        80 ms        1.5%
    ?                                                                 60 ms        1.1%
    recursiveClone <mwInit.lua:41>                                    60 ms        1.1%
    [others]                                                         340 ms        6.3%

Also I couldn't reproduce it locally… maybe it was just a hhvm thing?

Change 546211 had a related patch set uploaded (by Hoo man; owner: Hoo man):
[mediawiki/extensions/Wikibase@master] Don't update ParserOutput usages, unless really needed

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

I just purged the page and it is gone now:

Lua Profile:
    Scribunto_LuaSandboxCallback::getEntityStatements               2240 ms       41.6%
    Scribunto_LuaSandboxCallback::callParserFunction                1920 ms       35.7%
    Scribunto_LuaSandboxCallback::getSiteLinkPageName                280 ms        5.2%
    Scribunto_LuaSandboxCallback::gsub                               120 ms        2.2%
    Scribunto_LuaSandboxCallback::incrementStatsKey                  100 ms        1.9%
    Scribunto_LuaSandboxCallback::entityExists                       100 ms        1.9%
    init <Modul:Languages>                                            80 ms        1.5%
    Scribunto_LuaSandboxCallback::anchorEncode                        80 ms        1.5%
    ?                                                                 60 ms        1.1%
    recursiveClone <mwInit.lua:41>                                    60 ms        1.1%
    [others]                                                         340 ms        6.3%

Also I couldn't reproduce it locally… maybe it was just a hhvm thing?

The user I talked to changed relevant Lua modules while I was testing, so that different Lua functions might have been used here.

Change 546211 merged by jenkins-bot:
[mediawiki/extensions/Wikibase@master] Don't update ParserOutput usages, unless really needed

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

@hoo now that this is deployed, how is it performing?

@hoo now that this is deployed, how is it performing?

Well, this is to small to have an impact on the overall page save timings, I suppose… and we don't profile this ourselves. Besides the (obviously not very representative) micro-benchmark I mentioned in the commit message, I can only say that on the above page the relative time spent in Scribunto_LuaSandboxCallback::addStatementUsage went down from 12.6% to 11.4%. So we sadly don't have a good way to accurately assess this.