[Wikidata-bugs] [Maniphest] T265562: [6hr.] Investigation - Wikibase Lua: addStatementUsage seems unjustifiably expensive

[Lydia_Pintscher]

Lydia_Pintscher closed this task as "Resolved".
Lydia_Pintscher added a comment.


  I checked it again now and the addStatementUsage part takes 860 ms. While 
this is still large and we should improve it I am going to close this ticket 
because the spike seems to be gone and have been an issue with a deployment.

TASK DETAIL
  https://phabricator.wikimedia.org/T265562

EMAIL PREFERENCES
  https://phabricator.wikimedia.org/settings/panel/emailpreferences/

To: toan, Lydia_Pintscher
Cc: Tarrow, Pablo-WMDE, Lucas_Werkmeister_WMDE, toan, hoo, Lydia_Pintscher, 
RolandUnger, Aklapper, Akuckartz, Iflorez, alaa_wmde, Nandana, lucamauri, Lahi, 
Gq86, Darkminds3113, GoranSMilovanovic, QZanden, LawExplorer, Vali.matei, 
SundanceRaphael, _jensen, rosalieper, Scott_WUaS, Jonas, Volker_E, alex-mashin, 
Wikidata-bugs, aude, GWicke, Dinoguy1000, jayvdb, MrStradivarius, Jackmcbarn, 
Mbch331, Rxy, Jay8g
___
Wikidata-bugs mailing list
Wikidata-bugs@lists.wikimedia.org
https://lists.wikimedia.org/mailman/listinfo/wikidata-bugs

[Wikidata-bugs] [Maniphest] T265562: [6hr.] Investigation - Wikibase Lua: addStatementUsage seems unjustifiably expensive

[toan]

toan added a comment.


  We discussed the way forward for this task this morning and decided we will 
not spend more time investigate what could have been the root cause now ( even 
though it would be very satisfying ) but keep this ticket on the board and 
monitor if there any changes in the next deployments.

TASK DETAIL
  https://phabricator.wikimedia.org/T265562

EMAIL PREFERENCES
  https://phabricator.wikimedia.org/settings/panel/emailpreferences/

To: toan
Cc: Tarrow, Pablo-WMDE, Lucas_Werkmeister_WMDE, toan, hoo, Lydia_Pintscher, 
RolandUnger, Aklapper, Akuckartz, Iflorez, darthmon_wmde, alaa_wmde, Nandana, 
lucamauri, Lahi, Gq86, Darkminds3113, GoranSMilovanovic, QZanden, LawExplorer, 
Vali.matei, SundanceRaphael, _jensen, rosalieper, Scott_WUaS, Jonas, Volker_E, 
alex-mashin, Wikidata-bugs, aude, GWicke, Dinoguy1000, jayvdb, MrStradivarius, 
Jackmcbarn, Mbch331, Rxy, Jay8g
___
Wikidata-bugs mailing list
Wikidata-bugs@lists.wikimedia.org
https://lists.wikimedia.org/mailman/listinfo/wikidata-bugs

[Wikidata-bugs] [Maniphest] T265562: [6hr.] Investigation - Wikibase Lua: addStatementUsage seems unjustifiably expensive

[RolandUnger]

RolandUnger added a comment.


  I was surprised, too. And I did not made any changes (yesterday morning I 
only added some maintenance categories). The computing times for 
`addStatementUsage` oscillate (between 400 and 900 ms) but they are clearly 
reduced. I think yesterday the 1.36.0-wmf.14 Mediawiki branch was deployed at 
Wikivoyage. Maybe that means to find the cause we had to look for it outside of 
Wikibase. Unless I'm very much mistaken `addStatementUsage` only makes a 
registration of entities and properties used. This should not be expensive. But 
I have no idea what happens at the registration and what went wrong.
  
  As you can see: our main problem is 
Scribunto_LuaSandboxCallback::callParserFunction which takes between 40 and 50 
% of total Lua time (250 expensive parser function calls). But this is a 
Kartographer problem and therefore another stuff.

TASK DETAIL
  https://phabricator.wikimedia.org/T265562

EMAIL PREFERENCES
  https://phabricator.wikimedia.org/settings/panel/emailpreferences/

To: toan, RolandUnger
Cc: Tarrow, Pablo-WMDE, Lucas_Werkmeister_WMDE, toan, hoo, Lydia_Pintscher, 
RolandUnger, Aklapper, Akuckartz, Iflorez, darthmon_wmde, alaa_wmde, Nandana, 
lucamauri, Lahi, Gq86, Darkminds3113, GoranSMilovanovic, QZanden, LawExplorer, 
Vali.matei, SundanceRaphael, _jensen, rosalieper, Scott_WUaS, Jonas, Volker_E, 
alex-mashin, Wikidata-bugs, aude, GWicke, Dinoguy1000, jayvdb, MrStradivarius, 
Jackmcbarn, Mbch331, Rxy, Jay8g
___
Wikidata-bugs mailing list
Wikidata-bugs@lists.wikimedia.org
https://lists.wikimedia.org/mailman/listinfo/wikidata-bugs

[Wikidata-bugs] [Maniphest] T265562: [6hr.] Investigation - Wikibase Lua: addStatementUsage seems unjustifiably expensive

[toan]

toan added a subscriber: Tarrow.
toan added a comment.


  I did some more tests with @Tarrow yesterday evening and seems this might 
just have been noise as we could not reproduce it again.
  
  Looking at the profile of https://de.wikivoyage.org/wiki/Halle_(Saale) this 
morning there is a drastic decrease of time spent on 
`Scribunto_LuaSandboxCallback::addStatementUsage` did you find a solution 
yourself @RolandUnger?
  



TASK DETAIL
  https://phabricator.wikimedia.org/T265562

EMAIL PREFERENCES
  https://phabricator.wikimedia.org/settings/panel/emailpreferences/

To: toan
Cc: Tarrow, Pablo-WMDE, Lucas_Werkmeister_WMDE, toan, hoo, Lydia_Pintscher, 
RolandUnger, Aklapper, Akuckartz, Iflorez, darthmon_wmde, alaa_wmde, Nandana, 
lucamauri, Lahi, Gq86, Darkminds3113, GoranSMilovanovic, QZanden, LawExplorer, 
Vali.matei, SundanceRaphael, _jensen, rosalieper, Scott_WUaS, Jonas, Volker_E, 
alex-mashin, Wikidata-bugs, aude, GWicke, Dinoguy1000, jayvdb, MrStradivarius, 
Jackmcbarn, Mbch331, Rxy, Jay8g
___
Wikidata-bugs mailing list
Wikidata-bugs@lists.wikimedia.org
https://lists.wikimedia.org/mailman/listinfo/wikidata-bugs

[Wikidata-bugs] [Maniphest] T265562: [6hr.] Investigation - Wikibase Lua: addStatementUsage seems unjustifiably expensive

[RolandUnger]

RolandUnger added a comment.


  The computing times for `Scribunto_LuaSandboxCallback::getEntity` and 
`Scribunto_LuaSandboxCallback::addStatementUsage` did not change much, but only 
that of `Scribunto_LuaSandboxCallback::addStatementUsage` changed drastically. 
The number of properties fetched increased within the last four weeks only by 
one which cannot explain the increase of computing time of this simple 
function. Maybe there is a problem with the accumulator/cache or database.

TASK DETAIL
  https://phabricator.wikimedia.org/T265562

EMAIL PREFERENCES
  https://phabricator.wikimedia.org/settings/panel/emailpreferences/

To: toan, RolandUnger
Cc: Pablo-WMDE, Lucas_Werkmeister_WMDE, toan, hoo, Lydia_Pintscher, 
RolandUnger, Aklapper, Akuckartz, Iflorez, darthmon_wmde, alaa_wmde, Nandana, 
lucamauri, Lahi, Gq86, Darkminds3113, GoranSMilovanovic, QZanden, LawExplorer, 
Vali.matei, SundanceRaphael, _jensen, rosalieper, Scott_WUaS, Jonas, Volker_E, 
alex-mashin, Wikidata-bugs, aude, GWicke, Dinoguy1000, jayvdb, MrStradivarius, 
Jackmcbarn, Mbch331, Rxy, Jay8g
___
Wikidata-bugs mailing list
Wikidata-bugs@lists.wikimedia.org
https://lists.wikimedia.org/mailman/listinfo/wikidata-bugs

[Wikidata-bugs] [Maniphest] T265562: [6hr.] Investigation - Wikibase Lua: addStatementUsage seems unjustifiably expensive

[toan]

toan added a comment.


  Ok, so after looking at this yesterday and today I've tried to replicate my 
local environment to what has been and what currently is deployed on 
https://de.wikivoyage.org/wiki/Spezial:Version
  
  LuaSandbox3.0.3
  Lua   5.1.5
  
  Installing luasandbox for mediawiki-docker-dev with the following command.
  
apt-get install liblua5.1-0-dev

git clone https://gerrit.wikimedia.org/r/mediawiki/php/luasandbox.git

phpize && ./configure && make && sudo make install

# add this extension=luasandbox.so
nano /opt/docker/etc/php/php.ini

service php-fpm restart
  
  In Scribunto Enginge.php comment out the following to get the function 
profile on line 71
  
#if ( $t < 1.0 ) {
#   return $ret;
#}
  
  rolling my development environment back to `1.36.0-wmf.8` for Wikibase, core, 
Scribunto
  
  using a simple module such as
  
local p = {} --p stands for package

function p.testAddStatementUsage( frame, entityID, property )

return mw.wikibase.getBestStatements ( 'Q1', 'P1' )
end

return p
  
  addStatementUsage is only called once and the profile returns the following
  


  
  Running it a couple of times `Lua time usage` seems vary between `0.011 - 
0.014`
  
  Moving forward to `1.36.0-wmf.13` on Wikibase, core, Scribunto
  
  I'm running the same script and now getting the following results.
  


  
  Running it a couple of times it seems we indeed have an increase in the `Lua 
time usage` running the same scripts varying between `0.022 -  0.024`

TASK DETAIL
  https://phabricator.wikimedia.org/T265562

EMAIL PREFERENCES
  https://phabricator.wikimedia.org/settings/panel/emailpreferences/

To: toan
Cc: Pablo-WMDE, Lucas_Werkmeister_WMDE, toan, hoo, Lydia_Pintscher, 
RolandUnger, Aklapper, Akuckartz, Iflorez, darthmon_wmde, alaa_wmde, Nandana, 
lucamauri, Lahi, Gq86, Darkminds3113, GoranSMilovanovic, QZanden, LawExplorer, 
Vali.matei, SundanceRaphael, _jensen, rosalieper, Scott_WUaS, Jonas, Volker_E, 
alex-mashin, Wikidata-bugs, aude, GWicke, Dinoguy1000, jayvdb, MrStradivarius, 
Jackmcbarn, Mbch331, Rxy, Jay8g
___
Wikidata-bugs mailing list
Wikidata-bugs@lists.wikimedia.org
https://lists.wikimedia.org/mailman/listinfo/wikidata-bugs

[Wikidata-bugs] [Maniphest] T265562: [6hr.] Investigation - Wikibase Lua: addStatementUsage seems unjustifiably expensive

[RolandUnger]

RolandUnger added a comment.


  I am not sure if T263999  is the 
real cause for this bug. But I cannot exclude this cause, or maybe both bugs 
have a joint cause elsewhere. `addStatementUsage` only registers the use of an 
entity and a property and has maybe nothing to do with functions in which a 
language was specified.
  
  Today I added some additional code/maintenance to our vCard script to check 
the usage of getLabel and getLabelByLang Wikibase functions.
  
  Both functions are //not used// in the article of Halle (Saale) 
 but in the article of 
Eisenbahnmuseen in Europa 
. In any case, the 
bug still occurs. Otherwise properties with type `monolingualtext` are used. 
There are several maintenance categories to check usage of getLabel: getLabel 
used  
(temporarily added), label from Wikidata 
, unknown 
label 
, 
and opening-hours label from Wikidata 
.

TASK DETAIL
  https://phabricator.wikimedia.org/T265562

EMAIL PREFERENCES
  https://phabricator.wikimedia.org/settings/panel/emailpreferences/

To: toan, RolandUnger
Cc: Pablo-WMDE, Lucas_Werkmeister_WMDE, toan, hoo, Lydia_Pintscher, 
RolandUnger, Aklapper, Akuckartz, Iflorez, darthmon_wmde, alaa_wmde, Nandana, 
lucamauri, Lahi, Gq86, Darkminds3113, GoranSMilovanovic, QZanden, LawExplorer, 
Vali.matei, SundanceRaphael, _jensen, rosalieper, Scott_WUaS, Jonas, Volker_E, 
alex-mashin, Wikidata-bugs, aude, GWicke, Dinoguy1000, jayvdb, MrStradivarius, 
Jackmcbarn, Mbch331, Rxy, Jay8g
___
Wikidata-bugs mailing list
Wikidata-bugs@lists.wikimedia.org
https://lists.wikimedia.org/mailman/listinfo/wikidata-bugs

[Wikidata-bugs] [Maniphest] T265562: [6hr.] Investigation - Wikibase Lua: addStatementUsage seems unjustifiably expensive

[toan]

toan added a comment.


  > Leaving T263999 : Some lua-calls 
with language specified does not end up in formatterCache because it has 
similar buzz words but I don't know if they are related.
  
  Yeah I'm suspecting this could be the culprit ( or significantly contributing 
to the slow-down ).
  
  Looking at the code of vcard 
 which 
in turn uses this module 

 to make all the requests there is a lot of language dependent calls being made 
that would end up not using the cache and make this go a lot slower.
  
  However no real insights into when that ended up being deployed and used on 
https://de.wikivoyage.org/wiki/Halle_(Saale).
  
  It also does not really match what @RolandUnger writes here.
  
  > Some days ago a single addStatementUsage call costs only about 1 ms but now 
6 ms . The question arose: why this drastic change: more than 500 %? I have no 
idea why an access to an entity table already loaded is now as much expensive.

TASK DETAIL
  https://phabricator.wikimedia.org/T265562

EMAIL PREFERENCES
  https://phabricator.wikimedia.org/settings/panel/emailpreferences/

To: toan
Cc: Pablo-WMDE, Lucas_Werkmeister_WMDE, toan, hoo, Lydia_Pintscher, 
RolandUnger, Aklapper, Akuckartz, Iflorez, darthmon_wmde, alaa_wmde, Nandana, 
lucamauri, Lahi, Gq86, Darkminds3113, GoranSMilovanovic, QZanden, LawExplorer, 
Vali.matei, SundanceRaphael, _jensen, rosalieper, Scott_WUaS, Jonas, Volker_E, 
alex-mashin, Wikidata-bugs, aude, GWicke, Dinoguy1000, jayvdb, MrStradivarius, 
Jackmcbarn, Mbch331, Rxy, Jay8g
___
Wikidata-bugs mailing list
Wikidata-bugs@lists.wikimedia.org
https://lists.wikimedia.org/mailman/listinfo/wikidata-bugs

[Wikidata-bugs] [Maniphest] T265562: [6hr.] Investigation - Wikibase Lua: addStatementUsage seems unjustifiably expensive

[Pablo-WMDE]

Pablo-WMDE added a comment.


  Leaving T263999: Some lua-calls with language specified does not end up in 
formatterCache  because it has 
similar buzz words but I don't know if they are related.

TASK DETAIL
  https://phabricator.wikimedia.org/T265562

EMAIL PREFERENCES
  https://phabricator.wikimedia.org/settings/panel/emailpreferences/

To: toan, Pablo-WMDE
Cc: Pablo-WMDE, Lucas_Werkmeister_WMDE, toan, hoo, Lydia_Pintscher, 
RolandUnger, Aklapper, Akuckartz, Iflorez, darthmon_wmde, alaa_wmde, Nandana, 
lucamauri, Lahi, Gq86, Darkminds3113, GoranSMilovanovic, QZanden, LawExplorer, 
Vali.matei, SundanceRaphael, _jensen, rosalieper, Scott_WUaS, Jonas, Volker_E, 
alex-mashin, Wikidata-bugs, aude, GWicke, Dinoguy1000, jayvdb, MrStradivarius, 
Jackmcbarn, Mbch331, Rxy, Jay8g
___
Wikidata-bugs mailing list
Wikidata-bugs@lists.wikimedia.org
https://lists.wikimedia.org/mailman/listinfo/wikidata-bugs

[Wikidata-bugs] [Maniphest] T265562: [6hr.] Investigation - Wikibase Lua: addStatementUsage seems unjustifiably expensive

[toan]

toan claimed this task.

TASK DETAIL
  https://phabricator.wikimedia.org/T265562

EMAIL PREFERENCES
  https://phabricator.wikimedia.org/settings/panel/emailpreferences/

To: toan
Cc: Lucas_Werkmeister_WMDE, toan, hoo, Lydia_Pintscher, RolandUnger, Aklapper, 
Akuckartz, Iflorez, darthmon_wmde, alaa_wmde, Nandana, lucamauri, Lahi, Gq86, 
Darkminds3113, GoranSMilovanovic, QZanden, LawExplorer, Vali.matei, 
SundanceRaphael, _jensen, rosalieper, Scott_WUaS, Jonas, Volker_E, alex-mashin, 
Wikidata-bugs, aude, GWicke, Dinoguy1000, jayvdb, MrStradivarius, Jackmcbarn, 
Mbch331, Rxy, Jay8g
___
Wikidata-bugs mailing list
Wikidata-bugs@lists.wikimedia.org
https://lists.wikimedia.org/mailman/listinfo/wikidata-bugs

[Wikidata-bugs] [Maniphest] T265562: [6hr.] Investigation - Wikibase Lua: addStatementUsage seems unjustifiably expensive

[ItamarWMDE]

ItamarWMDE updated the task description.

TASK DETAIL
  https://phabricator.wikimedia.org/T265562

EMAIL PREFERENCES
  https://phabricator.wikimedia.org/settings/panel/emailpreferences/

To: ItamarWMDE
Cc: Lucas_Werkmeister_WMDE, toan, hoo, Lydia_Pintscher, RolandUnger, Aklapper, 
Akuckartz, Iflorez, darthmon_wmde, alaa_wmde, Nandana, lucamauri, Lahi, Gq86, 
Darkminds3113, GoranSMilovanovic, QZanden, LawExplorer, Vali.matei, 
SundanceRaphael, _jensen, rosalieper, Scott_WUaS, Jonas, Volker_E, alex-mashin, 
Wikidata-bugs, aude, GWicke, Dinoguy1000, jayvdb, MrStradivarius, Jackmcbarn, 
Mbch331, Rxy, Jay8g
___
Wikidata-bugs mailing list
Wikidata-bugs@lists.wikimedia.org
https://lists.wikimedia.org/mailman/listinfo/wikidata-bugs

[Wikidata-bugs] [Maniphest] T265562: [6hr.] Investigation - Wikibase Lua: addStatementUsage seems unjustifiably expensive

[ItamarWMDE]

ItamarWMDE renamed this task from "Wikibase Lua: addStatementUsage seems 
unjustifiably expensive" to "[6hr.] Investigation - Wikibase Lua: 
addStatementUsage seems unjustifiably expensive".

TASK DETAIL
  https://phabricator.wikimedia.org/T265562

EMAIL PREFERENCES
  https://phabricator.wikimedia.org/settings/panel/emailpreferences/

To: ItamarWMDE
Cc: Lucas_Werkmeister_WMDE, toan, hoo, Lydia_Pintscher, RolandUnger, Aklapper, 
Akuckartz, Iflorez, darthmon_wmde, alaa_wmde, Nandana, lucamauri, Lahi, Gq86, 
Darkminds3113, GoranSMilovanovic, QZanden, LawExplorer, Vali.matei, 
SundanceRaphael, _jensen, rosalieper, Scott_WUaS, Jonas, Volker_E, alex-mashin, 
Wikidata-bugs, aude, GWicke, Dinoguy1000, jayvdb, MrStradivarius, Jackmcbarn, 
Mbch331, Rxy, Jay8g
___
Wikidata-bugs mailing list
Wikidata-bugs@lists.wikimedia.org
https://lists.wikimedia.org/mailman/listinfo/wikidata-bugs