Fugliness

Jump to navigation Jump to search

Ok, here's an excerpt from an example output. Out of 13 seconds (it's slower when profiling is on), Article::getContent takes up only 0.314916 seconds. There are 254 Article::getContents calls, but only 157 call Article::loadContent calls, and 174 Revision::loadText (this is what loads the revision text from the db) calls. Revision::loadText takes up only 0.088527 seconds, so the database is definitely not the bottleneck. The parser is. In fact, the number of wfMsgReal calls greatly concerns me...

(format is seconds count name)

13.215451      1 - -total
3.611685  26819 - wfMsgReal
3.447692   1287 - Parser::parse
3.399038   1287 - Parser::parse-OutputPage::parse
2.164450    138 - WikiEditorHooks::addModules
2.131158   1292 - Parser::internalParse
1.788212   2005 - Parser::replaceVariables
1.526407    694 - Parser::transformMsg
1.496620    694 - Parser::preprocess
1.345063   3222 - PPFrame_DOM::expand
0.996161   1142 - Parser::braceSubstitution
0.904751   3313 - Preprocessor_DOM::preprocessToObj
0.775065      1 - Setup.php
0.762118      1 - Setup.php-SetupSession
0.580727   2004 - Parser::clearState
0.411560   3308 - Preprocessor_DOM::preprocessToXml
0.314916    254 - Article::getContent
0.302848    157 - Article::loadContent
0.278424   3313 - Preprocessor_DOM::preprocessToObj-loadXML
0.274240    795 - Database::query
-- Nx / talk21:46, 30 November 2010

You're right that it's not the major cause, but if I was a DBA on a system taking 1/3s to return this little content.... I'd be concerned. Is that the only call getting content? Remember - I know nothing about MW but loadContent seems to take a while too.

I know MySQL is only an open source database, not a proper product, but I wouldn't expect a database to be taking this long over a simple query based on a very few params.

SuspectedReplicant retire me21:53, 30 November 2010

The db stuff is much less than that actually - I'll have to insert more profiling calls to figure out why loadcontent takes so long (I have an idea), but the actual db access is in Revision::loadText, which is only 0.088 seconds. The profiling info also contains all the database queries, but I didn't write them down - they were really quick, so it's definitely not the database. And even 0.3 seconds is relatively small compared to the total.

-- Nx / talk22:09, 30 November 2010

True, but I hope you're right that the DB stuff is less than 0.3s - it should be (essentially) zero for a system of this size.

I'm not trying to annoy here, but please just take a look at the indexing anyway? Yes, it's mainly down to the parser, but every little helps.

SuspectedReplicant retire me22:20, 30 November 2010