Page MenuHomePhabricator

Publicly expose (publish) slow parse logs for public Wikimedia wikis
Closed, ResolvedPublic

Description

I'm filing this as a follow-up to T47830 as I couldn't find another task about this.

We should publicly expose slow parse logs for public Wikimedia wikis. https://gerrit.wikimedia.org/r/49678 is one approach.

Event Timeline

MZMcBride raised the priority of this task from to Needs Triage.
MZMcBride updated the task description. (Show Details)

Change 49678 merged by Ori.livneh:
Rsyncing slow-parse logs from fluorine to dumps.wikimedia.org

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

I've notified the it.wiki template wikiproject, see https://www.wikidata.org/wiki/Q5413052 for a list. I guess we should notify them all. Ok, just sent a short message to 27 of them.

Nemo_bis triaged this task as Medium priority.Jun 8 2015, 1:58 PM
Nemo_bis set Security to None.
Nemo_bis removed a project: MediaWiki-Parser.
jeremyb-phone edited subscribers, added: jeremyb; removed: jeremyb-phone.

Re-opening, because I think there is more work the performance team should do before we can consider this resolved. The format of the logs is not very friendly and their existence is not documented. We should make these logs more discoverable and provide a web interface for browsing them.

provide a web interface for browsing them

+1.

Here is a 5-line excerpt from https://dumps.wikimedia.org/other/slow-parse/slow-parse.log-20150802.gz, to demonstrate the format:

2015-08-01 08:33:25 mw1060 enwiki slow-parse INFO: 3.39  Charles,_Prince_of_Wales {"private":false}
2015-08-01 08:33:25 mw1135 enwiki slow-parse INFO: 3.38  List_of_Portuguese_football_transfers_winter_2013–14 {"private":false}
2015-08-01 08:33:27 mw1185 enwiki slow-parse INFO: 3.00  Wikipedia:WikiProject_Biography/Arts_and_entertainment {"private":false}
2015-08-01 08:33:27 mw1257 eswiki slow-parse INFO: 4.53  Racing_Club {"private":false}
2015-08-01 08:33:30 mw1038 enwiki slow-parse INFO: 5.35  Legendre_transformation {"private":false}

And here is a field-by-field breakdown of the first line:

#FieldMeaningUseful?
02015-08-01Date of parse (UTC).
108:33:25Time of parse (UTC).
2mw1060App server𐄂
3enwikiWiki
4slow-parseLog name𐄂
5INFO:Log level𐄂
63.39Parsing time in seconds
7Charles,_Prince_of_WalesPage title
8{"private":false}Log message metadata𐄂

@Nemo_bis, would you be willing to volunteer to provide Peter with usability feedback and answer any editor-related questions he may have? If so, stop by #wikimedia-perf and say hello to phedenskog. :)

The slow-parse entries now use the new LoggerFactory in MediaWiki, with the "time" and "title" properties exposed in the JSON payload.

poolcounter: Convert slow-parse to use LoggerFactory
https://gerrit.wikimedia.org/r/234036

2015-08-26 22:57:02 mw1172 enwiki slow-parse INFO: 3.84 Chile_national_football_team {"time":"3.84","title":"Chile_national_football_team"}
2015-08-26 22:57:02 mw1176 svwiki slow-parse INFO: 4.56 Goyencourt {"time":"4.56","title":"Goyencourt"}
2015-08-26 22:57:03 mw1094 svwiki slow-parse INFO: 4.93 Pontaumur {"time":"4.93","title":"Pontaumur"}

I created an example query in the private Kibana dashboard for this data:
https://logstash.wikimedia.org/#/dashboard/elasticsearch/slow-parse

Past 24 hours:

Screen Shot 2015-09-08 at 19.35.39.png (1×2 px, 413 KB)

@whym said on #wikimedia-tech:

Is there any quick way to list "heavy" templates (because of expensive parser functions etc)?

Maybe you can give suggestions on how to present the slow-parse.log entries for a wiki usefully. :)

I note that the rsync job has been broken since August 2, this must be when ferm rules were applied on dataset1001 without including fluorine in the yaml list of rsync clients for datasets in hiera. That's now fixed. And now back to your regularly scheduled programming...

In human readable form: https://tools.wmflabs.org/slow-parse/

Having created that and browsed through some listings, I'm not sure how useful it is for larger wikis...we need some more details I think before this is useful for template editors.