Profiling/Search only 20050913

From Meta, a Wikimedia project coordination wiki

Sample rate of 1:300, about 12 hours. The database is very heavily loaded because adler recently went offline, hence the large query time and frequent high-load backoff (LoadBalancer::getReaderIndex-sleep). The time for LinkCache::addLinkObj is misleading: this is the first query, so it gets hit with the connection setup and the backoff time. The addLinkObj query itself is at 4.6%.

+------------------------------------------------------------------------+-------------------+---------+---------------------+----------------------+
| name                                                                   | total             | count   | each                | percent              |
+------------------------------------------------------------------------+-------------------+---------+---------------------+----------------------+
| -total                                                                 |  3653392.02929688 |    5362 |     661.30643420172 |                  100 |
| main-action                                                            |  3306256.11523438 |    5362 |     598.62142889999 |      90.498257201012 |
| SpecialPage::executePath                                               |  3304249.83203125 |    5362 |     598.25488994948 |      90.443341572275 |
| Special:Search                                                         |  3303839.81054688 |    5362 |      598.1803116668 |      90.432118536776 |
| LuceneSearch::execute                                                  |  3303582.76171875 |    5362 |     598.13112434027 |      90.425082641748 |
| Database::query                                                        |  2158525.43554688 |  247453 |     8.4244802968237 |      59.082776177248 |
| LuceneSearch::showHit                                                  |  1750740.84863281 |   22691 |       76.2924323867 |      47.920968639376 |
| LoadBalancer::getConnection                                            |  1311393.98583984 |  216820 |     5.8418519140633 |      35.895244072458 |
| LinkCache::addLinkObj                                                  |  1305905.43505859 |    8667 |     147.00789258781 |       35.74501243191 |
| LoadBalancer::getReaderIndex                                           |  1278683.94433594 |   65778 |     19.184501487464 |      34.999910605871 |
| Revision::loadText                                                     |  872151.131347656 |   21366 |     40.143356445229 |      23.872366402341 |
| query: SELECT page_namespace,page_title,page_latest,rev_id,rev_page,re |  727673.255371094 |   24032 |     30.271770843267 |      19.917743552726 |
| LoadBalancer::getReaderIndex-sleep 10.0.0.1 [4]                        |  697551.961669922 |    1307 |     522.43570324423 |      19.093268832805 |
| query: SELECT old_text,old_flags FROM `text` WHERE old_id = 'X' LIMIT  |  573109.055908203 |   21366 |     26.526283004129 |      15.687039641856 |
| Revision::getRevisionText                                              |  292694.522583008 |   21366 |     13.340473660657 |      8.0115826671724 |
| query: SELECT cur_text FROM `cur` WHERE cur_id = 'X' LIMIT N           |  285230.646484375 |   10978 |     25.489448261009 |      7.8072827716567 |
| query: UPDATE `profiling` SET pf_count=pf_count+N, pf_time=pf_time + N |  245546.545349121 |  143407 |     1.5180155791082 |      6.7210565792026 |
| LoadBalancer::getReaderIndex-sleep 10.0.0.2 [1]                        |   234099.58782959 |     399 |     575.25341682831 |      6.4077324840128 |
| LoadBalancer::getReaderIndex-sleep 10.0.0.3 [3]                        |  176725.968322754 |     514 |     336.71425724771 |       4.837311925618 |
| query: SELECT page_id FROM `page` WHERE page_namespace = 'X' LIMIT N   |  168571.147338867 |    8667 |     19.185797994692 |      4.6140996089957 |
| memcached::get                                                         |  160349.498901367 |   22729 |     6.4918527979603 |      4.3890581031411 |
| Setup.php                                                              |  153299.778320312 |    5362 |     27.664141250185 |      4.1960943991498 |
| -overhead-total                                                        |  123966.505737305 | 2067466 |   0.058590848864367 |      3.3931892538005 |
| main-cleanup                                                           |  123526.586425781 |    5362 |     22.237256527118 |      3.3811478602682 |
| LuceneSearchSet::newFromQuery                                          |  106608.988433838 |    1259 |     78.874322281139 |      2.9180823623343 |
| wfMsgReal                                                              |  98682.2930908203 |  145766 |    0.65443328292652 |      2.7011142603772 |
| OutputPage::output                                                     |   96519.208190918 |    5362 |     17.611921557797 |      2.6419066833486 |
| Output-skin                                                            |  95574.1776123047 |    1292 |     72.437176426144 |      2.6160394736148 |
| SkinTemplate::outputPage                                               |  95471.5723876953 |    1292 |     72.362537396451 |      2.6132309815673 |
| LoadBalancer::openConnection                                           |  91105.5581970215 |  225150 |    0.36323111103347 |      2.4937252138954 |
| MessageCache::load                                                     |  74354.7918701172 |    5362 |     13.152689830398 |      2.0352262027688 |
| MessageCache::load-fromcache                                           |  74296.2145385742 |    5362 |     13.140390117499 |      2.0336228344176 |
| Parser::parse                                                          |  63761.7535400391 |    5792 |     10.341208447401 |      1.7452754324947 |
| Setup.php-User                                                         |  60161.1501083374 |    5362 |      10.73130281255 |      1.6467203526449 |
| -overhead-internal                                                     |  46497.8706359863 | 2287815 |    0.01980227523691 |      1.2727314852366 |
| Parser::internalParse                                                  |  44701.9720153809 |    5792 |     7.0822714977208 |      1.2235744660554 |
| SkinTemplate::outputPage-stuff                                         |  41350.6183624268 |    1292 |     32.355249646166 |      1.1318418070339 |
| Setup.php-includes                                                     |   40569.283782959 |    5362 |     7.3481972272644 |      1.1104552552157 |
| LuceneSearchSet::newFromQuery-contact-10.0.0.17                        |  38760.0112304688 |     405 |     88.152438921273 |      1.0609321671381 |
| query: SHOW STATUS                                                     |  37053.2183303833 |    7591 |     4.8176205881445 |      1.0142141339678 |
| SkinTemplate::outputPage-stuff2                                        |  33644.0623626709 |    1292 |      24.75467664481 |     0.92089932021738 |
| LuceneSearchSet::newFromQuery-contact-10.0.0.16                        |  31438.6182060242 |     365 |     79.150973845395 |     0.86053229311049 |
| LuceneSearchSet::newFromQuery-contact-10.0.0.230                       |  27419.0697402954 |     396 |     67.942045427952 |     0.75050992393971 |
| query: BEGIN                                                           |  25924.8100204468 |   11724 |     1.9622105527672 |     0.70960931136197 |
| query: COMMIT                                                          |  24721.2807769775 |    8386 |     2.6309656015893 |     0.67666652192635 |
| query: SELECT N FROM `user_newtalk` WHERE user_ip = 'X'                |  23605.4379959106 |    1262 |     18.251922688966 |     0.64612387081968 |
| Setup.php-language1                                                    |   16424.475692749 |    5362 |     3.0042586724726 |     0.44956784163976 |
| query: UPDATE `profiling` SET pf_count=pf_count+N, pf_time=pf_time + N |   15297.540309906 |    6106 |     2.2314272280352 |     0.41872156580059 |
| Setup.php-extensions                                                   |  13160.3367156982 |    5362 |     2.4236570651418 |     0.36022240729066 |
| SkinTemplate::buildSidebar                                             |  11822.9652366638 |    1292 |     8.5644210743848 |     0.32361611187232 |
| Parser::replaceVariables                                               |  11557.6800918579 |   15020 |    0.75172035395796 |     0.31635477384239 |
| LoadBalancer::getReaderIndex-sleep 10.0.0.24 [2]                       |  11073.2387695312 |      11 |       1012.45234375 |     0.30309473171053 |
| ParserOptions::initialiseFromUser                                      |  11046.3022079468 |   42896 |    0.24962189736512 |     0.30235742891443 |
| Title::newFromText                                                     |  10936.2306480408 |   39322 |    0.25780466493455 |     0.29934456965861 |
| parser::variableSubstitution                                           |  10853.9768753052 |    6654 |     1.5908477395459 |     0.29709313394966 |
| Title::secureAndSplit                                                  |  10670.3576583862 |   32408 |    0.30529442714791 |     0.29206714124353 |
| Parser::initialiseVariables                                            |  10528.8447647095 |    6654 |     1.5429492519775 |     0.28819367536464 |
| Parser::replaceLinkHolders                                             |  9697.16476917267 |    5792 |     1.6750175211373 |     0.26542907772859 |
| Parser::replaceLinkHolders-check                                       |  9491.60726726055 |     431 |     21.839137850395 |     0.25980259416856 |
| query: SELECT page_id, page_namespace, page_title FROM `page` WHERE (p |  9217.85874652863 |     431 |     21.233692236694 |     0.25230959811074 |
| Database::masterPosWait                                                |  8700.61602127552 |     186 |     55.005617923981 |     0.23815172178361 |
| Setup.php-MessageCache                                                 |  8112.29402923584 |    5362 |     1.4802974247413 |     0.22204827634655 |
| MessageCache::initialise                                               |  7924.65259933472 |    5362 |     1.4440029606461 |     0.21691218833857 |
| LuceneSearch::showHit-extract                                          |  7526.48334503174 |   21366 |    0.33512281722597 |     0.20601356998308 |
| MessageCache::initialise-parseropt                                     |  7347.83422470093 |    5362 |     1.3345101920726 |     0.20112361788108 |
| Title::getInterwikiLink                                                |  6837.80371952057 |    2597 |     2.3741413614384 |     0.18716315316527 |
| ParserOptions::initialiseFromUser-skin                                 |  6434.42755508423 |   42896 |    0.14510769040205 |     0.17612201218719 |
| query: SELECT user_name,user_password,user_newpassword,user_email,user |  6002.45195287466 |     190 |     30.462002708012 |      0.1642980524603 |
| User::getSkin                                                          |  5824.01183700562 |   16086 |    0.34897068117074 |     0.15941382119144 |
| query: INSERT IGNORE INTO `profiling` (pf_name,pf_count,pf_time,pf_ser |  5364.31858539581 |    2008 |     2.4640214240688 |       0.146831178871 |
| Parser::internalTidy                                                   |   3948.4476776123 |    5792 |    0.66558451671323 |     0.10807621098282 |
| Setup.php-misc2                                                        |  3687.29138755798 |    5362 |    0.66805700394703 |     0.10092788723436 |
| query: SHOW PROCESSLIST                                                |  3544.59922122955 |     730 |     4.0683059944987 |    0.097022142513179 |
| Setup.php-OutputPage                                                   |  3450.76272773743 |    5362 |    0.61542241474995 |    0.094453666621744 |
| main-misc-setup                                                        |  3201.52879905701 |    5362 |     0.5815458117346 |    0.087631679638639 |
| Linker::makeKnownLinkObj                                               |  3026.13010025024 |   25757 |    0.11431470393353 |    0.082830697499295 |
| SkinTemplate::outputPage-stuff4                                        |  2671.71301841736 |    1292 |     2.0281513868311 |    0.073129655864814 |
| Setup.php-memcached                                                    |  2625.25629234314 |    5362 |    0.47431432316829 |     0.07185805058124 |
| query: SELECT ug_group FROM `user_groups` WHERE ug_user = 'X'          |  2335.44179356098 |     190 |     11.948989466463 |      0.0639252994158 |
| SkinTemplate::buildNavUrls                                             |  2141.78249454498 |    1292 |     1.6295263892384 |    0.058624491359532 |
| SkinTemplate::outputPage-execute                                       |  2023.61906909943 |    1292 |     1.5565937471665 |    0.055390142992371 |
| Parser::removeHTMLtags                                                 |  1920.24408626556 |    5792 |    0.32488523722319 |    0.052560581258922 |
| Parser::replaceInternalLinks                                           |  1663.32240724564 |    5792 |    0.28030113358285 |    0.045528166534205 |
| Setup.php-misc1                                                        |   1411.9880027771 |    5362 |    0.25160667652007 |    0.038648685699598 |
| Setup.php-language2                                                    |  1411.33811616898 |    5362 |    0.26023645627889 |    0.038630897118386 |
| SkinTemplate-translate                                                 |  1265.82999229431 |   15504 |   0.081156621210876 |    0.034648074505651 |
| User::loadDefaults1                                                    |  1253.00650882721 |    5362 |    0.22815592801888 |    0.034297072385861 |
| Setup.php-SetupSession                                                 |  1224.41734683514 |    5362 |    0.20603911211435 |    0.033514534903904 |
| Parser::replaceInternalLinks-setup                                     |  1162.02664852142 |    5792 |    0.19823367130607 |    0.031806787752396 |
| User::loadDefaults2                                                    |   999.68568611145 |    5362 |    0.19025655307134 |    0.027363219662573 |
| User::loadDefaults3                                                    |   988.90836763382 |    5362 |    0.17768295604564 |    0.027068224808717 |
| SkinTemplate::buildPersonalUrls                                        |  890.392167016864 |    1292 |    0.78770051198048 |    0.024371656802137 |
| query: SELECT N FROM `user_newtalk` WHERE user_id = 'X'                |  692.439526572824 |      30 |     22.472933294333 |    0.018953332164194 |
| Parser::doBlockLevels                                                  |  631.148532390594 |    5792 |    0.10510293889109 |    0.017275685919533 |
| SkinTemplate::setupUserCss                                             |  604.194374084473 |    1292 |    0.44883191182396 |    0.016537901469084 |
| Setup.php-database                                                     |  504.882015943527 |    5362 |   0.090708517737377 |    0.013819541179672 |
| query: SHOW SLAVE STATUS                                               |  490.528789252043 |     154 |     2.3959711042463 |    0.013426667199097 |
| SkinTemplate::outputPage-stuff3                                        |  454.528604269028 |    1292 |    0.34301545359514 |    0.012441276507534 |
| Parser::doHeadings                                                     |  422.168395519257 |    5792 |   0.071639048573405 |    0.011555518601175 |
| MessageCache::initialise-parser                                        |  392.729645729065 |    5362 |    0.07145053659056 |     0.01074972635238 |
| wfRunHooks                                                             |  379.331456184387 |   24460 |   0.015829593920634 |    0.010382993479553 |
| Parser::doBlockLevels-paragraph                                        |  340.128687858582 |    8367 |   0.038901952347654 |    0.009309942243566 |
| query: UPDATE `profiling` SET pf_count=pf_count+N, pf_time=pf_time + N |  332.950412064791 |     149 |     2.2332437248963 |    0.009113459749045 |
| SkinTemplate::buildContentActionUrls                                   |  258.699085235596 |    1292 |    0.19193359819879 |   0.0070810655730637 |
| Parser::replaceExternalLinks                                           |  229.527857065201 |    5792 |   0.038593517782231 |   0.0062825958786956 |
| Parser::doTableStuff                                                   |  202.656133890152 |    5792 |   0.033598698880795 |   0.0055470678280632 |
| Parser::doAllQuotes                                                    |  165.711998462677 |    5792 |   0.028132425189282 |   0.0045358394920068 |
| Parser::removeHTMLcomments                                             |  163.787240862846 |    5792 |   0.027820645596773 |   0.0044831553676535 |
| Parser::replaceLinkHolders-construct                                   |  143.424250543118 |     431 |    0.33324527648091 |   0.0039257832007347 |
| Parser::replaceFreeExternalLinks                                       |  141.304367780685 |    5792 |   0.023648356570296 |   0.0038677581449665 |
| wfGetSiteNotice                                                        |  106.709489881992 |    1292 |   0.078552299301793 |   0.0029208332701851 |
| SkinTemplate::outputPage-init                                          |  90.1909040510654 |    1292 |   0.066781851590204 |      0.0024686894625 |
| Setup.php-BlockCache                                                   |  67.8488015830517 |    5362 |   0.012169163673828 |   0.0018571453881479 |
| query: SHOW MASTER STATUS                                              |  58.7247154563665 |      47 |     1.4423383932847 |   0.0016074025175904 |
| SkinTemplate::setupUserJs                                              |  48.7638045549393 |    1292 |   0.037982065649532 |   0.0013347542274111 |
| Linker::makeBrokenLinkObj                                              |  48.5858715474606 |     431 |    0.11425837008673 |   0.0013298838766233 |
| Parser::magicISBN                                                      |  43.9196759611368 |    5792 |  0.0074811321845477 |   0.0012021615969198 |
| Skin::initPage                                                         |  40.4621353447437 |    1292 |   0.030207892568454 |   0.0011075224071294 |
| Title::userCanEdit                                                     |  28.2806125776842 |    5792 |  0.0070439222395318 |  0.00077409192199741 |
| Parser::replaceLinkHolders-replace                                     |  13.5688576512039 |     431 |   0.031413090792387 |  0.00037140437003185 |
| User::loadDefaults4                                                    |  5.10151518136263 |      36 |    0.14277150744089 |  0.00013963777061025 |
| LoadBalancer::waitFor                                                  |  3.58956893533468 |     186 |   0.018609746895274 |  9.8253045568327e-05 |
| query: SELECT iw_url,iw_local,iw_trans FROM `interwiki` WHERE iw_prefi |  1.79496216773987 |       5 |    0.35005542635918 |  4.9131386759097e-05 |
| Profile section ended by close(): OutputPage::output                   |                 0 |    4070 |                   0 |                    0 |
| Profile section ended by close(): -total                               |                 0 |    5362 |                   0 |                    0 |
| Profile section ended by close(): main-cleanup                         |                 0 |    4070 |                   0 |                    0 |
| main-updates                                                           | -6.92927968804725 |    5362 | -0.0013271406051082 | -0.00018966701718515 |
+------------------------------------------------------------------------+-------------------+---------+---------------------+----------------------+