On 6/20/13, Johannes Weberhofer <jweberho...@weberhofer.at> wrote: > Dear all! > > After upgrading a server to a complete new system > (apache/php/mysql->mariadb) I have massive performance-problems when a large > page is to be rendered. > > I have added a profiling log; I do not think, it is related to the database > upgrade, as the database have a very low CPU usage while rendering, while > Apache's CPU usage is very high for around 16 seconds. This happens > especially with large pages. I have already tried to remove all extensions > which did not make any difference. > > Do you have any ideas where to start? > > Best regards, > Johannes > > > Start request GET /wiki/IS_(Projekttagebuch) > HTTP HEADERS: > HOST: test.com > USER-AGENT: Mozilla/5.0 (X11; Linux x86_64; rv:21.0) Gecko/20100101 > Firefox/21.0 > ACCEPT: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8 > ACCEPT-LANGUAGE: de-at,de;q=0.8,en-us;q=0.5,en;q=0.3 > ACCEPT-ENCODING: gzip, deflate > REFERER: > https://test.com/w/index.php?title=IS_(Projekttagebuch)&action=edit§ion=515 > COOKIE: mediawikiUserName=Web; > mediawiki_session=qd955vfopmq2ri2limkteimp8rc8pu9v; mediawikiUserID=3; > mediawikiPostEditRevision72824=1 > DNT: 1 > CONNECTION: keep-alive > CACHES: EmptyBagOStuff[main] SqlBagOStuff[message] SqlBagOStuff[parser] > [cookie] session_set_cookie_params: "0", "/", "", "1", "1" > Class LanguageDe not found; skipped loading > LocalisationCache: using store LCStore_DB > Connected to database 0 at localhost > Fully initialised > Title::getRestrictionTypes: applicable restrictions to [[IS > (Projekttagebuch)]] are {edit,move} > [ContentHandler] Created handler for wikitext: WikitextContentHandler > User: cache miss for user 3 > User: loading options for user 3 from database. > User: logged in from session > User: loading options for user 3 from override cache. > Connected to database 0 at localhost > MessageCache::load: Loading de... got from global cache > Unstubbing $wgParser on call of $wgParser::firstCallInit from > MessageCache::getParser > Parser: using preprocessor: Preprocessor_DOM > Unstubbing $wgLang on call of $wgLang::_unstub from > ParserOptions::__construct > OutputPage::checkLastModified: client did not send If-Modified-Since header > Article::tryFileCache(): not cacheable > Article::view using parser cache: yes > Parser cache options found. > ParserOutput cache found. > Article::view: showing parser cache contents > Title::getRestrictionTypes: applicable restrictions to [[IS > (Projekttagebuch)]] are {edit,move} > Title::getRestrictionTypes: applicable restrictions to [[IS > (Projekttagebuch)]] are {edit,move} > Use of wfMsg was deprecated in MediaWiki 1.21. [Called from > PdfBookHooks::onSkinTemplateNavigation in > /usr/share/mediawiki/extensions/PdfBook/PdfBook.hooks.php at line 173] > Use of wfMsgReal was deprecated in MediaWiki 1.21. [Called from wfMsg in > /usr/share/mediawiki/includes/GlobalFunctions.php at line 1444] > Use of wfMsgGetKey was deprecated in MediaWiki 1.21. [Called from wfMsgReal > in /usr/share/mediawiki/includes/GlobalFunctions.php at line 1542] > Title::getRestrictionTypes: applicable restrictions to [[IS > (Projekttagebuch)]] are {edit,move} > Class PEAR_Error not found; skipped loading > OutputPage::sendCacheControl: private caching; Thu, 20 Jun 2013 14:20:08 GMT > ** > DatabaseBase::query: Writes done: UPDATE `page` SET page_counter = > page_counter + 1 WHERE page_id = '4292' > LoadBalancer::reuseConnection: this connection was not opened as a foreign > connection > LoadBalancer::reuseConnection: this connection was not opened as a foreign > connection > LoadBalancer::reuseConnection: this connection was not opened as a foreign > connection > LoadBalancer::reuseConnection: this connection was not opened as a foreign > connection > LoadBalancer::reuseConnection: this connection was not opened as a foreign > connection > LoadBalancer::reuseConnection: this connection was not opened as a foreign > connection > LoadBalancer::reuseConnection: this connection was not opened as a foreign > connection > LoadBalancer::reuseConnection: this connection was not opened as a foreign > connection > LoadBalancer::reuseConnection: this connection was not opened as a foreign > connection > LoadBalancer::reuseConnection: this connection was not opened as a foreign > connection > LoadBalancer::reuseConnection: this connection was not opened as a foreign > connection > LoadBalProfiling data > Profile section ended by close(): -total > 20130620142023 16.176 /wiki/IS_(Projekttagebuch) > > Profiling data > Name > Calls Total Each % Mem > -total > 1 16176.342 16176.342 100.000% 36200744 ( 16176.342 - > 16176.342) [0] > MediaWiki::main > 1 16039.443 16039.443 99.154% 20009099 ( 16039.443 - > 16039.443) [3614] > OutputPage::output > 1 15748.575 15748.575 97.356% 5828987 ( 15748.575 - > 15748.575) [740] > MediaWiki::performRequest > 1 270.768 270.768 1.674% 11315010 ( 270.768 - > 270.768) [2836] > MediaWiki::performAction > 1 261.395 261.395 1.616% 9682971 ( 261.395 - > 261.395) [2816] > Article::view > 1 261.341 261.341 1.616% 9687972 ( 261.341 - > 261.341) [2815] > Output-skin > 1 87.482 87.482 0.541% 5723286 ( 87.482 - > 87.482) [736] > SkinTemplate::outputPage > 1 87.438 87.438 0.541% 6600319 ( 87.438 - > 87.438) [735] > Linker::link > 522 72.747 0.139 0.450% 2660882 ( 0.108 - > 4.421) [2101] > Setup.php > 1 52.204 52.204 0.323% 8908692 ( 52.204 - > 52.204) [40] > -overhead-total > 3736 49.771 0.013 0.308% 4366944 ( 49.771 - > 49.771) [3736] > SkinTemplate::outputPage-stuff5 > 1 40.932 40.932 0.253% 3391878 ( 40.932 - > 40.932) [247] > Setup.php-globals > 1 39.662 39.662 0.245% 6704621 ( 39.662 - > 39.662) [30] > Linker::linkUrl > 522 28.209 0.054 0.174% 393323 ( 0.044 - > 1.055) [522] > Title::getLinkURL > 528 26.079 0.049 0.161% 363712 ( 0.040 - > 1.040) [0] > DatabaseBase::query > 131 24.619 0.188 0.152% 351600 ( 0.086 - > 1.253) [135] > -overhead-internal > 3736 19.885 0.005 0.123% 1344960 ( 0.004 - > 0.090) [0] > LocalisationCache::getItem-load > 15 19.628 1.309 0.121% 1964445 ( 0.232 - > 15.358) [85] > SkinTemplate::outputPage-execute > 1 17.706 17.706 0.109% 819599 ( 17.706 - > 17.706) [264] > LocalisationCache::getSubitem-load > 66 17.270 0.262 0.107% 50735 ( 0.229 - > 0.346) [264] > Parser::transformMsg > 9 13.786 1.532 0.085% 1286503 ( 0.487 - > 7.202) [182] > Parser::preprocess > 9 13.751 1.528 0.085% 1286919 ( 0.484 - > 7.202) [173] > SkinTemplate::outputPage-stuff4 > 1 13.482 13.482 0.083% 1178525 ( 13.482 - > 13.482) [57] > WebStart.php-conf > 1 12.944 12.944 0.080% 1228568 ( 12.944 - > 12.944) [0] > Linker::titleAttrib > 34 11.949 0.351 0.074% 94503 ( 0.033 - > 0.693) [200] > ResourceLoader::makeModuleResponse > 2 11.389 5.694 0.070% 1669457 ( 1.286 - > 10.102) [17] > Parser::replaceVariables > 10 10.621 1.062 0.066% 867523 ( 0.394 - > 4.549) [150] > query: SELECT lc_value FROM `lNn_cache` WHERE lc_lang = 'X' LIMIT N > 84 9.916 0.118 0.061% 221718 ( 0.099 - > 0.242) [2] > LoadBalancer::getConnection > 121 9.131 0.075 0.056% 1178146 ( 0.006 - > 6.235) [133] > SkinTemplate::outputPage-stuff2 > 1 8.694 8.694 0.054% 1114227 ( 8.694 - > 8.694) [69] > MediaWiki::initializeArticle > 1 8.463 8.463 0.052% 1554850 ( 8.463 - > 8.463) [15] > StubObject::_unstub-wgParser > 1 8.037 8.037 0.050% 1535576 ( 8.037 - > 8.037) [0] > ParserCache::get > 1 7.942 7.942 0.049% 1841868 ( 7.942 - > 7.942) [4] > LoadBalancer::openConnection > 121 7.814 0.065 0.048% 1171653 ( 0.001 - > 6.216) [12] > JobQueue::isEmpty > 11 7.299 0.664 0.045% 9551 ( 0.599 - > 1.047) [46] > User::load > 2 7.137 3.569 0.044% 759113 ( 3.443 - > 3.695) [25] > Parser::firstCallInit > 1 6.615 6.615 0.041% 951738 ( 6.615 - > 6.615) [88] > PPFrame_DOM::expand > 25 6.305 0.252 0.039% 391382 ( 0.026 - > 1.690) [110] > ResourceLoader::makeModuleResponse-user.tokens > 1 5.943 5.943 0.037% 1349528 ( 5.943 - > 5.943) [0] > RequestContext::getSkin-createskin > 1 5.670 5.670 0.035% 1232951 ( 5.670 - > 5.670) [1] > Linker::linkAttribs > 522 5.332 0.010 0.033% 719644 ( 0.008 - > 0.083) [4] > Linker::accesskey > 32 5.072 0.159 0.031% 77658 ( 0.028 - > 0.387) [70] > Setup.php-includes > 1 5.045 5.045 0.031% 908872 ( 5.045 - > 5.045) [0] > SkinTemplate::buildContentNavigationUrls > 1 5.037 5.037 0.031% 179175 ( 5.037 - > 5.037) [37] > -setup > 1 5.029 5.029 0.031% 0 ( 5.029 - > 5.029) [0] > Parser::braceSubstitution > 11 4.887 0.444 0.030% 332464 ( 0.169 - > 1.621) [99] > main-try-filecache > 1 4.740 4.740 0.029% 499995 ( 4.740 - > 4.740) [14] > SkinTemplate::outputPage-stuff3 > 1 4.155 4.155 0.026% 35875 ( 4.155 - > 4.155) [78] > DeferredUpdates::doUpdates > 1 3.651 3.651 0.023% 841 ( 3.651 - > 3.651) [16] > Parser::clearState > 10 3.502 0.350 0.022% 446782 ( 0.067 - > 2.631) [20] > SkinTemplate::buildNavUrls > 1 3.144 3.144 0.019% 423187 ( 3.144 - > 3.144) [5] > Parser::braceSubstitution-modifiers > 11 2.742 0.249 0.017% 129155 ( 0.036 - > 1.427) [51] > SkinTemplate::buildPersonalUrls > 1 2.514 2.514 0.016% 13057 ( 2.514 - > 2.514) [26] > MessageCache::parse > 1 2.383 2.383 0.015% 31668 ( 2.383 - > 2.383) [58] > hook: ParserFirstCallInit > 1 2.349 2.349 0.015% 345593 ( 2.349 - > 2.349) [26] > Parser::parse > 1 2.322 2.322 0.014% 33405 ( 2.322 - > 2.322) [57] > Parser::parse-MessageCache::parse > 1 2.322 2.322 0.014% 33422 ( 2.322 - > 2.322) [56] > MessageBlobStore::get > 1 2.301 2.301 0.014% 224772 ( 2.301 - > 2.301) [4] > query: SELECT keyname,value,exptime FROM `objectcache` WHERE keyname = 'X' > 6 2.207 0.368 0.014% 49424 ( 0.228 - > 0.841) [0] > SkinTemplate::outputPage-init > 1 2.083 2.083 0.013% 56230 ( 2.083 - > 2.083) [11] > MessageCache::load > 1 2.075 2.075 0.013% 20555 ( 2.075 - > 2.075) [14] > Setup.php-memcached > 1 2.062 2.062 0.013% 346048 ( 2.062 - > 2.062) [0] > Skin::initPage > 1 2.053 2.053 0.013% 54759 ( 2.053 - > 2.053) [10] > Skin::buildSidebar > 1 1.966 1.966 0.012% 28186 ( 1.966 - > 1.966) [6] > query: SELECT N FROM `job` WHERE job_cmd = 'X' LIMIT N > 11 1.937 0.176 0.012% 23414 ( 0.153 - > 0.337) [2] > MagicWord::load > 145 1.927 0.013 0.012% 223354 ( 0.006 - > 0.514) [6] > MessageCache::load-fromcache > 1 1.925 1.925 0.012% 19700 ( 1.925 - > 1.925) [13] > LinkBatch::executeInto > 1 1.921 1.921 0.012% 59376 ( 1.921 - > 1.921) [9] > SkinTemplate::buildContentNavigationUrls-live > 1 1.920 1.920 0.012% 9447 ( 1.920 - > 1.920) [19] > Preprocessor_DOM::preprocessToObj > 11 1.907 0.173 0.012% 21316 ( 0.126 - > 0.243) [22] > Parser::internalParse > 1 1.835 1.835 0.011% 31448 ( 1.835 - > 1.835) [45] > query: COMMIT > 2 1.758 0.879 0.011% 832 ( 0.751 - > 1.008) [0] > ResourceLoader::filter > 3 1.729 0.576 0.011% 4298 ( 0.508 - > 0.675) [6] > DatabaseMysql::open > 2 1.723 0.861 0.011% 15375 ( 0.794 - > 0.929) [10] > ResourceLoader::__construct > 1 1.699 1.699 0.011% 208214 ( 1.699 - > 1.699) [2] > Parser::braceSubstitution-pfunc > 2 1.569 0.785 0.010% 193500 ( 0.210 - > 1.359) [13] > Parser::callParserFunction > 2 1.529 0.764 0.009% 186542 ( 0.193 - > 1.336) [11] > Parser::callParserFunction-pfunc-plural > 2 1.507 0.754 0.009% 186544 ( 0.184 - > 1.323) [9] > Revision::loadText > 1 1.506 1.506 0.009% 370083 ( 1.506 - > 1.506) [5] > wfCite > 1 1.493 1.493 0.009% 288896 ( 1.493 - > 1.493) [0] > hook: SkinTemplateNavigation > 1 1.439 1.439 0.009% 85489 ( 1.439 - > 1.439) [7] > Setup.php-misc1 > 1 1.372 1.372 0.008% 195664 ( 1.372 - > 1.372) [0] > query: SELECT old_text,old_flags FROM `text` WHERE old_id = 'X' LIMIT N > 1 1.250 1.250 0.008% 2392 ( 1.250 - > 1.250) [0] > Title::getUserPermissionsErrorsInternal > 10 1.172 0.117 0.007% 76205 ( 0.022 - > 0.632) [3] > Preprocessor_DOM::preprocessToXml > 11 1.127 0.102 0.007% 177616 ( 0.073 - > 0.161) [0] > PdfBookHooks::onSkinTemplateNavigation > 1 0.957 0.957 0.006% 3906 ( 0.957 - > 0.957) [6] > Linker::link-checkPageExistence > 522 0.940 0.002 0.006% 192741 ( 0.001 - > 0.069) [3] > query: SELECT page_namespace,page_title,page_touched FROM `page` WHERE (pag > 4 0.925 0.231 0.006% 11408 ( 0.125 - > 0.361) [0] > query: UPDATE `page` SET page_counter = page_counter + N WHERE page_id = 'X > 1 0.923 0.923 0.006% 600 ( 0.923 - > 0.923) [0] > Setup.php-exception > 1 0.919 0.919 0.006% 256160 ( 0.919 - > 0.919) [0] > query: SELECT page_id,page_namespace,page_title,page_len,page_is_redirect,p > 1 0.835 0.835 0.005% 4104 ( 0.835 - > 0.835) [0] > ResourceLoader::makeModuleResponse-user.cssprefs > 1 0.768 0.768 0.005% 2829 ( 0.768 - > 0.768) [3] > ResourceLoader::makeModuleResponse-user.options > 1 0.740 0.740 0.005% 4320 ( 0.740 - > 0.740) [0] > wfRegisterParserFunctions > 1 0.726 0.726 0.004% 50775 ( 0.726 - > 0.726) [19] > LinkCache::addLinkObj > 7 0.692 0.099 0.004% 7524 ( 0.019 - > 0.526) [4] > ResourceLoader::register > 2 0.658 0.329 0.004% 47848 ( 0.137 - > 0.522) [0] > LinkBatch::doQuery > 1 0.626 0.626 0.004% 5780 ( 0.626 - > 0.626) [4] > dbconnect-localhost > 2 0.622 0.311 0.004% 14552 ( 0.304 - > 0.319) [0] > Preprocessor_DOM::preprocessToObj-loadXML > 11 0.588 0.053 0.004% 18456 ( 0.041 - > 0.071) [0] > MediaWiki_I18N::translate > 5 0.568 0.114 0.004% 3979 ( 0.052 - > 0.314) [5] > Setup.php-extensions > 1 0.545 0.545 0.003% 43405 ( 0.545 - > 0.545) [3] > wfMsgReal > 1 0.537 0.537 0.003% 1299 ( 0.537 - > 0.537) [5] > User::getEffectiveGroups > 1 0.517 0.517 0.003% 59687 ( 0.517 - > 0.517) [1] > User::getAutomaticGroups > 1 0.505 0.505 0.003% 59032 ( 0.505 - > 0.505) [0] > hook: MakeGlobalVariablesScript > 1 0.458 0.458 0.003% 66894 ( 0.458 - > 0.458) [2] > Parser::braceSubstitution-setup > 11 0.430 0.039 0.003% 10462 ( 0.032 - > 0.046) [11] > Parser::doDoubleUnderscore > 1 0.400 0.400 0.002% 30212 ( 0.400 - > 0.400) [13] > query: SET NAMES binary > 2 0.396 0.198 0.002% 1544 ( 0.188 - > 0.209) [0] > hook: ParserClearState > 10 0.391 0.039 0.002% 9831 ( 0.024 - > 0.064) [10] > query: SELECT page_id,page_namespace,page_title,page_len,page_is_redirect,p > 1 0.389 0.389 0.002% 3656 ( 0.389 - > 0.389) [0] > SkinTemplate::outputPage-stuff > 1 0.353 0.353 0.002% 6143 ( 0.353 - > 0.353) [1] > query: SELECT rev_id,rev_page,rev_text_id,rev_timestamp,rev_comment,rev_use > 1 0.350 0.350 0.002% 7688 ( 0.350 - > 0.350) [0] > query: BEGIN > 3 0.346 0.115 0.002% 1808 ( 0.084 - > 0.132) [0] > hook: BeforePageDisplay > 1 0.344 0.344 0.002% 42622 ( 0.344 - > 0.344) [2] > query: SELECT page_id,page_len,page_is_redirect,page_latest,page_content_mo > 1 0.333 0.333 0.002% 3360 ( 0.333 - > 0.333) [0] > Setup.php-extensions-MathHooks::setup > 1 0.299 0.299 0.002% 42224 ( 0.299 - > 0.299) [0] > Parser::replaceInternalLinks2-setup > 1 0.282 0.282 0.002% 2899 ( 0.282 - > 0.282) [5] > Parser::replaceInternalLinks2 > 1 0.281 0.281 0.002% 2898 ( 0.281 - > 0.281) [6] > query: SELECT mr_blob,mr_resource,mr_timestamp FROM `msg_resource` WHERE mr > 1 0.267 0.267 0.002% 2784 ( 0.267 - > 0.267) [0] > query: SELECT page_id,page_namespace,page_title,page_restrictions,page_coun > 1 0.261 0.261 0.002% 5064 ( 0.261 - > 0.261) [0] > query: SET sql_mode = 'X' > 2 0.254 0.127 0.002% 1104 ( 0.101 - > 0.153) [0] > Sanitizer::removeHTMLtags > 3 0.253 0.084 0.002% 70717 ( 0.038 - > 0.151) [3] > query: SELECT page_namespace,page_title,page_touched FROM `page` WHERE (pag > 1 0.251 0.251 0.002% 2600 ( 0.251 - > 0.251) [0] > query: SELECT user_name,up_value FROM `user` LEFT JOIN `user_properties` ON > 1 0.251 0.251 0.002% 2360 ( 0.251 - > 0.251) [0] > query: UPDATE `site_stats` SET ss_total_views=ss_total_views+N > 1 0.242 0.242 0.001% 616 ( 0.242 - > 0.242) [0] > query: SELECT user_id,user_name,user_real_name,user_password,user_newpasswo > 1 0.236 0.236 0.001% 5352 ( 0.236 - > 0.236) [0] > Setup.php-session > 1 0.228 0.228 0.001% 3128 ( 0.228 - > 0.228) [0] > SkinTemplate::buildContentNavigationUrls-edit > 1 0.225 0.225 0.001% 1791 ( 0.225 - > 0.225) [1] > StubObject::_unstub-wgLang > 1 0.196 0.196 0.001% 368 ( 0.196 - > 0.196) [0] > query: SELECT wl_notificationtimestamp FROM `watchlist` WHERE wl_user = 'X' > 1 0.170 0.170 0.001% 2320 ( 0.170 - > 0.170) [0] > Skin::getSkinNames-init > 1 0.168 0.168 0.001% 3312 ( 0.168 - > 0.168) [0] > Linker::linkAttribs-getClasses > 4 0.165 0.041 0.001% 2848 ( 0.020 - > 0.060) [0] > query: SELECT up_property,up_value FROM `user_properties` WHERE up_user = ' > 1 0.125 0.125 0.001% 2680 ( 0.125 - > 0.125) [0] > Cite::clearState > 10 0.123 0.012 0.001% 2720 ( 0.007 - > 0.028) [0] > query: SELECT ug_group FROM `user_groups` WHERE ug_user = 'X' > 1 0.119 0.119 0.001% 1944 ( 0.119 - > 0.119) [0] > query: SELECT user_id FROM `user_newtalk` WHERE user_id = 'X' LIMIT N > 1 0.107 0.107 0.001% 2096 ( 0.107 - > 0.107) [0] > query: SELECT pr_type,pr_expiry,pr_level,pr_cascade FROM `page_restrictions > 1 0.107 0.107 0.001% 2760 ( 0.107 - > 0.107) [0] > Parser::doBlockLevels > 1 0.097 0.097 0.001% 2023 ( 0.097 - > 0.097) [1] > Parser::doMagicLinks > 1 0.092 0.092 0.001% 1112 ( 0.092 - > 0.092) [0] > Skin::getSiteNotice > 1 0.071 0.071 0.000% 390 ( 0.071 - > 0.071) [2] > WikiEditorHooks::makeGlobalVariablesScript > 1 0.060 0.060 0.000% 1992 ( 0.060 - > 0.060) [0] > hook: ParserAfterParse > 1 0.057 0.057 0.000% 1559 ( 0.057 - > 0.057) [1] > Skin::getCachedNotice > 2 0.053 0.026 0.000% 2672 ( -0.000 - > 0.053) [0] > hook: ArticleFromTitle > 1 0.051 0.051 0.000% 599 ( 0.051 - > 0.051) [1] > hook: ParserCloned > 1 0.051 0.051 0.000% 5887 ( 0.051 - > 0.051) [1] > Parser::doBlockLevels-paragraph > 1 0.051 0.051 0.000% 544 ( 0.051 - > 0.051) [0] > ParserOptions::initialiseFromUser > 2 0.048 0.024 0.000% 2352 ( 0.023 - > 0.025) [0] > efCategoryTreeSetHooks > 1 0.042 0.042 0.000% 3199 ( 0.042 - > 0.042) [1] > Setup.php-extensions-efLucenePrefixSetup > 1 0.040 0.040 0.000% 272 ( 0.040 - > 0.040) [0] > SpecialPageFactory::getList > 1 0.037 0.037 0.000% 1560 ( 0.037 - > 0.037) [0] > Parser::replaceExternalLinks > 1 0.037 0.037 0.000% 744 ( 0.037 - > 0.037) [0] > Parser::doAllQuotes > 1 0.031 0.031 0.000% 1328 ( 0.031 - > 0.031) [0] > BaseTemplate::getToolbox > 1 0.029 0.029 0.000% 5688 ( 0.029 - > 0.029) [0] > VectorHooks::beforePageDisplay > 1 0.029 0.029 0.000% 456 ( 0.029 - > 0.029) [0] > Cite::cloneState > 1 0.028 0.028 0.000% 5176 ( 0.028 - > 0.028) [0] > Cite::checkRefsNoReferences > 2 0.024 0.012 0.000% 592 ( 0.006 - > 0.018) [0] > hook: ParserBeforeTidy > 1 0.023 0.023 0.000% 1423 ( 0.023 - > 0.023) [1] > Parser::initialiseVariables > 1 0.023 0.023 0.000% 1856 ( 0.023 - > 0.023) [0] > hook: OutputPageParserOutput > 1 0.020 0.020 0.000% 631 ( 0.020 - > 0.020) [1] > SkinTemplate::buildContentActionUrls > 1 0.020 0.020 0.000% 1608 ( 0.020 - > 0.020) [0] > VectorHooks::makeGlobalVariablesScript > 1 0.019 0.019 0.000% 1512 ( 0.019 - > 0.019) [0] > Parser::doHeadings > 1 0.018 0.018 0.000% 648 ( 0.018 - > 0.018) [0] > efSyntaxHighlight_GeSHiSetup > 1 0.017 0.017 0.000% 1928 ( 0.017 - > 0.017) [0] > Parser::doTableStuff > 1 0.017 0.017 0.000% 2864 ( 0.017 - > 0.017) [0] > efCategoryTreeArticleFromTitle > 1 0.012 0.012 0.000% 272 ( 0.012 - > 0.012) [0] > wfSetupImageMap > 1 0.012 0.012 0.000% 1088 ( 0.012 - > 0.012) [0] > MediaWiki::checkMaxLag > 1 0.011 0.011 0.000% 408 ( 0.011 - > 0.011) [0] > Setup.php-extensions-efCategoryTree > 1 0.011 0.011 0.000% 1008 ( 0.011 - > 0.011) [0] > wfCiteBeforePageDisplay > 1 0.010 0.010 0.000% 440 ( 0.010 - > 0.010) [0] > MathHooks::onParserFirstCallInit > 1 0.010 0.010 0.000% 1216 ( 0.010 - > 0.010) [0] > MessageCache::saveToCaches > 1 0.008 0.008 0.000% 504 ( 0.008 - > 0.008) [0] > Revision::getRevisionText > 1 0.007 0.007 0.000% 912 ( 0.007 - > 0.007) [0] > LanguageGetMagic > 1 0.007 0.007 0.000% 576 ( 0.007 - > 0.007) [0] > efCategoryTreeParserOutput > 1 0.004 0.004 0.000% 272 ( 0.004 - > 0.004) [0] > Sanitizer::removeHTMLcomments > 3 0.003 0.001 0.000% 1248 ( 0.001 - > 0.002) [0] > LinkHolderArray::replace > 1 0.003 0.003 0.000% 416 ( 0.003 - > 0.003) [0] > WebStart.php-ob_start > 1 0.002 0.002 0.000% 360 ( 0.002 - > 0.002) [0] > SkinTemplate::outputPage-stuff-head > 1 0.001 0.001 0.000% 376 ( 0.001 - > 0.001) [0] > Profile section ended by close(): -total > 1 0.000 0.000 0.000% 0 ( 0.000 - > 0.000) [3734] > > Total: 16.176341694734 > > Request ended normally > > -- > Johannes Weberhofer > Weberhofer GmbH, Austria, Vienna > > _______________________________________________ > Wikitech-l mailing list > Wikitech-l@lists.wikimedia.org > https://lists.wikimedia.org/mailman/listinfo/wikitech-l
For a starting place, I would try editing the output method of includes/OutputPage.php to add more wfProfileIn( __METHOD__ . '-someIdentifier' ); wfProfileOut( __METHOD__ . '-someIdentifier' ); around various lines, to try and get a better picture of which line is taking up so much time. --bawolff _______________________________________________ Wikitech-l mailing list Wikitech-l@lists.wikimedia.org https://lists.wikimedia.org/mailman/listinfo/wikitech-l
