Page MenuHomePhabricator
Create Task
Maniphest T50164

JobQueue does not scale for TTMServer
Closed, ResolvedPublic
Actions

Description

So yesterday we got a report that Special:Translations is not working on meta. I looked few ganglia stats but could not figure out anything specific.

Today with help of Max we have a theory:
Many concurrent updates slow solr down to crawling (1 every 2 seconds taking average of almost 20 s to finish). Also search requests take longer than 10 seconds and time out.

The JobQueue seems to actually work against us here. The lack of accessible statistics to examine JobQueue behavior is problematic.

Max proposed that we store the list of changes and use cronjob to push them in batches with a single thread.

No other solutions have been proposed.

RT-5085 should be related to this.

Version: master
Severity: critical
URL: https://meta.wikimedia.org/wiki/Special:SearchTranslations?query=amen&uselang=en
See Also:
https://rt.wikimedia.org/Ticket/Display.html?id=5085
https://bugzilla.wikimedia.org/show_bug.cgi?id=48266

Details

Reference
bz48164

Event Timeline

• bzimport raised the priority of this task from to High.Nov 22 2014, 1:44 AM
• bzimport added projects: MediaWiki-extensions-Translate, Performance Issue.
• bzimport set Reference to bz48164.
Nikerabbit created this task.May 6 2013, 5:09 PM
Nemo_bis added a comment.May 6 2013, 5:15 PM

(In reply to comment #0)

RT-5085 should be related to this.

It's the ops ticket about this bug.

The JobQueue seems to actually work against us here. The lack of accessible
statistics to examine JobQueue behavior is problematic.

Statistics exist now: https://ganglia.wikimedia.org/latest/graph_all_periods.php?c=Miscellaneous%20pmtpa&h=hume.wikimedia.org&v=823574&m=Global_JobQueue_length&r=hour&z=default&jr=&js=&st=1365625056&z=large

However the good old https://gdash.wikimedia.org/dashboards/jobq/ gives 503 now, and I assume *executed* job items are what matters?

Nemo_bis added a comment.May 9 2013, 1:06 AM

After updates have been disabled per bug 48266 comment 0 vanadium is back at normal load and since 2013-05-08 17.20 Special:SearchTranslations "works".

aaron added a comment.May 9 2013, 2:34 AM

*** Bug 48266 has been marked as a duplicate of this bug. ***

aaron added a comment.May 9 2013, 2:58 AM

Is the problem *frequent* updates and/or *concurrent* updates?

Anyway, one can simulate cron jobs with de-duplication + delayed jobs in the queue (Wikidata will do something similar soon). So if there was a job inserted for each event requires a TTM update, always posted to metawiki, to check the lists of changes for each wiki and do the updates, and that job had ignoreDuplicates() return true and had a delay set, it would basically act like a cron where any of the job runner servers can service it.

aaron added a comment.May 29 2013, 11:47 PM

Here is some profiling info from trying to use a single runJobs.php process.

  • 99% of time is in SolrTTMServer::update (no surprise)
  • It can be quite fast for some (hundreds) of jobs but very slow for others
  • The slow ones *seem* to involve empty translations

Output dump below:

aaron@mw1001:~$ sudo -u apache php /usr/local/apache/common/multiversion/MWScript.php runJobs.php metawiki --type TTMServerMessageUpdateJob --maxjobs 100 --profiler text
2013-05-29 23:02:14 TTMServerMessageUpdateJob Translations:Mobile_projects/Mobile_Gateway/Mobile_homepage_formatting/27 STARTING
2013-05-29 23:03:11 TTMServerMessageUpdateJob Translations:Mobile_projects/Mobile_Gateway/Mobile_homepage_formatting/27 t=56467 good
2013-05-29 23:03:11 TTMServerMessageUpdateJob Translations:Fundraising_2012/Translation/FAQ_short/1 STARTING
2013-05-29 23:03:24 TTMServerMessageUpdateJob Translations:Fundraising_2012/Translation/FAQ_short/1 t=13436 good
2013-05-29 23:03:24 TTMServerMessageUpdateJob Translations:Fundraising_2012/Translation/FAQ_short/2 STARTING
2013-05-29 23:03:38 TTMServerMessageUpdateJob Translations:Fundraising_2012/Translation/FAQ_short/2 t=13499 good
2013-05-29 23:03:38 TTMServerMessageUpdateJob CNBanner:B13_051120_plaintext_staycurious-lp-appeal STARTING
2013-05-29 23:03:39 TTMServerMessageUpdateJob CNBanner:B13_051120_plaintext_staycurious-lp-appeal t=799 good
2013-05-29 23:03:39 TTMServerMessageUpdateJob CNBanner:B13_051120_plaintext_staycurious-lp-appeal-template STARTING
2013-05-29 23:03:40 TTMServerMessageUpdateJob CNBanner:B13_051120_plaintext_staycurious-lp-appeal-template t=996 good
2013-05-29 23:03:40 TTMServerMessageUpdateJob CNBanner:B13_051120_plaintext_staycurious-lp-form-template STARTING
2013-05-29 23:03:40 TTMServerMessageUpdateJob CNBanner:B13_051120_plaintext_staycurious-lp-form-template t=556 good
2013-05-29 23:03:40 TTMServerMessageUpdateJob CNBanner:B13_051120_plaintext_staycurious-lp-form-countryspecific STARTING
2013-05-29 23:03:41 TTMServerMessageUpdateJob CNBanner:B13_051120_plaintext_staycurious-lp-form-countryspecific t=649 good
2013-05-29 23:03:41 TTMServerMessageUpdateJob CNBanner:B13_022000_survey_frYY_autohide-hide-cookie-name STARTING
2013-05-29 23:03:42 TTMServerMessageUpdateJob CNBanner:B13_022000_survey_frYY_autohide-hide-cookie-name t=1070 good
2013-05-29 23:03:42 TTMServerMessageUpdateJob CNBanner:B13_022000_survey_frYY_autohide-hide-cookie-max-count STARTING
2013-05-29 23:03:43 TTMServerMessageUpdateJob CNBanner:B13_022000_survey_frYY_autohide-hide-cookie-max-count t=898 good
2013-05-29 23:03:43 TTMServerMessageUpdateJob CNBanner:B13_022000_survey_frYY_autohide-hide-die-size STARTING
2013-05-29 23:03:44 TTMServerMessageUpdateJob CNBanner:B13_022000_survey_frYY_autohide-hide-die-size t=1237 good
2013-05-29 23:03:44 TTMServerMessageUpdateJob CNBanner:B13_022000_survey_itYY_autohide-hide-cookie-name STARTING
2013-05-29 23:03:44 TTMServerMessageUpdateJob CNBanner:B13_022000_survey_itYY_autohide-hide-cookie-name t=414 good
2013-05-29 23:03:44 TTMServerMessageUpdateJob CNBanner:B13_022000_survey_itYY_autohide-hide-cookie-max-count STARTING
2013-05-29 23:03:45 TTMServerMessageUpdateJob CNBanner:B13_022000_survey_itYY_autohide-hide-cookie-max-count t=720 good
2013-05-29 23:03:45 TTMServerMessageUpdateJob CNBanner:B13_022000_survey_itYY_autohide-hide-die-size STARTING
2013-05-29 23:03:47 TTMServerMessageUpdateJob CNBanner:B13_022000_survey_itYY_autohide-hide-die-size t=1497 good
2013-05-29 23:03:47 TTMServerMessageUpdateJob CNBanner:B13_022000_survey_jaYY_autohide-hide-cookie-name STARTING
2013-05-29 23:03:47 TTMServerMessageUpdateJob CNBanner:B13_022000_survey_jaYY_autohide-hide-cookie-name t=603 good
2013-05-29 23:03:47 TTMServerMessageUpdateJob CNBanner:B13_022000_survey_jaYY_autohide-hide-cookie-max-count STARTING
2013-05-29 23:03:48 TTMServerMessageUpdateJob CNBanner:B13_022000_survey_jaYY_autohide-hide-cookie-max-count t=556 good
2013-05-29 23:03:48 TTMServerMessageUpdateJob CNBanner:B13_022000_survey_jaYY_autohide-hide-die-size STARTING
2013-05-29 23:03:49 TTMServerMessageUpdateJob CNBanner:B13_022000_survey_jaYY_autohide-hide-die-size t=831 good
2013-05-29 23:03:49 TTMServerMessageUpdateJob CNBanner:B13_text_2013_dr_en-hide-cookie-name STARTING
2013-05-29 23:03:49 TTMServerMessageUpdateJob CNBanner:B13_text_2013_dr_en-hide-cookie-name t=609 good
2013-05-29 23:03:49 TTMServerMessageUpdateJob CNBanner:B13_text_2013_dr_en-hide-cookie-max-count STARTING
2013-05-29 23:03:50 TTMServerMessageUpdateJob CNBanner:B13_text_2013_dr_en-hide-cookie-max-count t=587 good
2013-05-29 23:03:50 TTMServerMessageUpdateJob CNBanner:B13_text_2009_dr_en-hide-cookie-name STARTING
2013-05-29 23:03:51 TTMServerMessageUpdateJob CNBanner:B13_text_2009_dr_en-hide-cookie-name t=741 good
2013-05-29 23:03:51 TTMServerMessageUpdateJob CNBanner:B13_text_2009_dr_en-hide-cookie-max-count STARTING
2013-05-29 23:03:51 TTMServerMessageUpdateJob CNBanner:B13_text_2009_dr_en-hide-cookie-max-count t=632 good
2013-05-29 23:03:51 TTMServerMessageUpdateJob Translations:Wikimedia_Foundation_elections/Board_elections/2013/Candidates/51 STARTING
2013-05-29 23:08:18 TTMServerMessageUpdateJob Translations:Wikimedia_Foundation_elections/Board_elections/2013/Candidates/51 t=267215 good

aaron added a comment.May 29 2013, 11:48 PM

Further runs had several slow similar Translations:Wikimedia_Foundation_elections/Board_elections/2013/Candidates instances.

Nikerabbit added a comment.May 30 2013, 6:46 AM

Is there a way to find the slow functions via profiling?

aaron added a comment.May 30 2013, 7:15 AM

(In reply to comment #7)

Is there a way to find the slow functions via profiling?

You mean methods inside of SolrTTMServer::update? It would help if there profiling calls in there I suppose (for all i/o at least).

Maybe strace might help here too...

gerritbot added a comment.Jun 6 2013, 12:33 PM

Related URL: https://gerrit.wikimedia.org/r/67249 (Gerrit Change Ie230f2e40e97fa1fb00f056d4631e64cbcbf9eae)

gerritbot added a comment.Jun 6 2013, 12:47 PM

Related URL: https://gerrit.wikimedia.org/r/67250 (Gerrit Change I8a54e5dd00d6e6298e59000b8bdeaf4135d3158a)

gerritbot added a comment.Jun 6 2013, 1:19 PM

Related URL: https://gerrit.wikimedia.org/r/67252 (Gerrit Change I61d03705a80f67762091ea3bde8fc2bbcc6ce520)

siebrand added a comment.Jun 6 2013, 1:39 PM

I submitted 3 patch sets that I expect will take away all issues. The main problem was a Solr that was not optimised.

Gerrit 67249 enables autoCommit in Solr, which makes it possible for Solr to batch a bunch of index updates and commit them in one go. All open updates will be committed after at most 5 seconds.

Gerrit 67250 ensures that Translate no longer requires immediate commits, but demands that Solr commits within 5 seconds using the commitWithin feature.

Gerrit 67252 increases ramBufferSizeMB from 32 (MB) to 100 (MB). This is the new default since Solr 4.1[1]. This reduces the number of shard merges at the cost of additional memory usage.

One possible easy optimisation remains, which is the mergeFactor. As I wasn't really able to choose between two evils at this point in time, and without access to the Solr admin to check what's actually happen, I think these changes should go live and we should see if any additional optimisation is needed before doing another round of updates.

[1] https://issues.apache.org/jira/browse/SOLR-4074

Nemo_bis added a comment.Jun 11 2013, 6:34 PM

Aaron says that TTMServerMessageUpdateJob jobs are running since yesterday and there doesn't seem to be a big backlog; there have never been many, so he also hadn't dropped any such job from the queue. Vanadium seems happy and Special:SearchTranslations works.
Can this bug be closed?

Nikerabbit added a comment.Jun 12 2013, 7:11 AM

I believe this has been fixed now.

Content licensed under Creative Commons Attribution-ShareAlike (CC BY-SA) 4.0 unless otherwise noted; code licensed under GNU General Public License (GPL) 2.0 or later and other open source licenses. By using this site, you agree to the Terms of Use, Privacy Policy, and Code of Conduct. · Wikimedia Foundation · Privacy Policy · Code of Conduct · Terms of Use · Disclaimer · CC-BY-SA · GPL · Credits