Profiling/1.3 beta 1 with internal profiler
Appearance
Internal profiler, Celeron 466, new skin, no PHPA. Preview operation on text copied from MediaWiki User's Guide: Editing overview. Equivalent testing conditions to Profiling/1.2.5 with internal profiler.
Profiling data Name Calls Total Each % Setup.php-includes 1 3702.753 3702.753 17.554% Setup.php-memcached 1 139.545 139.545 0.662% wfMsg 127 485.047 3.819 2.299% query: SELECT N FROM user_newtalk WHERE user_ip='X' 1 3.091 3.091 0.015% Setup.php-misc 1 1457.106 1457.106 6.908% Setup.php 1 5302.315 5302.315 25.137% Title::newFromText 102 277.478 2.720 1.315% Title::secureAndSplit 117 1774.946 15.170 8.414% query: SHOW COLUMNS FROM cur LIKE 'X'; 1 3.125 3.125 0.015% main-misc-setup 1 48.211 48.211 0.229% query: BEGIN 1 1.777 1.777 0.008% query: SELECT cur_id FROM cur WHERE cur_namespace=N AND cur_title='X' 69 436.286 6.323 2.068% LinkCache::addLinkObj 69 728.417 10.557 3.453% query: SELECT cur_restrictions FROM cur WHERE (cur_id=N) 1 3.951 3.951 0.019% query: SELECT * FROM ipblocks ORDER BY ipb_timestamp DESC 1 4.827 4.827 0.023% query: SELECT ss_total_views, ss_total_edits, ss_good_articles FROM site_stats WHERE ss_row_id=N 1 3.442 3.442 0.016% Parser::replaceVariables 23 1801.384 78.321 8.540% Skin::makeKnownLinkObj 11 72.773 6.616 0.345% Parser::removeHTMLtags 11 1050.110 95.465 4.978% Parser::replaceExternalLinks 11 879.538 79.958 4.170% Tokenizer::newFromString 11 0.579 0.053 0.003% Tokenizer::nextToken 515 2420.090 4.699 11.473% Parser::internalParse 11 11178.202 1016.200 52.992% Tokenizer::previewToken 77 1040.772 13.517 4.934% Parser::handleInternalLink-setup 76 110.393 1.453 0.523% Skin::makeBrokenLinkObj 66 553.298 8.383 2.623% Parser::handleInternalLink 76 3423.626 45.048 16.230% query: SELECT iw_url,iw_local FROM interwiki WHERE iw_prefix='X' 19 117.775 6.199 0.558% Parser::doBlockLevels 1 464.891 464.891 2.204% Parser::parse 1 11069.022 11069.022 52.475% query: COMMIT 1 1.775 1.775 0.008% Skin::initPage 1 1.756 1.756 0.008% query: SELECT user_id FROM user WHERE user_name='X' 1 8.001 8.001 0.038% OutputPage::output 1 3578.272 3578.272 16.964% -total 1 21093.943 21093.943 100.000% -overhead-internal 1409 323.174 0.229 1.532% -overhead-total 1409 589.790 0.419 2.796% Total: 21.0939428806
Another run, this time with a profiling bracket around doTokenizedParser()
Profiling data Name Calls Total Each % Setup.php-includes 1 3389.820 3389.820 18.147% Setup.php-memcached 1 132.032 132.032 0.707% wfMsg 127 441.487 3.476 2.363% query: SELECT N FROM user_newtalk WHERE user_ip='X' 1 2.331 2.331 0.012% Setup.php-misc 1 1345.642 1345.642 7.204% Setup.php 1 4869.865 4869.865 26.071% Title::newFromText 102 254.354 2.494 1.362% Title::secureAndSplit 117 1492.334 12.755 7.989% query: SHOW COLUMNS FROM cur LIKE 'X'; 1 2.888 2.888 0.015% main-misc-setup 1 50.978 50.978 0.273% query: BEGIN 1 1.608 1.608 0.009% query: SELECT cur_id FROM cur WHERE cur_namespace=N AND cur_title='X' 69 359.155 5.205 1.923% LinkCache::addLinkObj 69 650.182 9.423 3.481% query: SELECT cur_restrictions FROM cur WHERE (cur_id=N) 1 3.601 3.601 0.019% query: SELECT * FROM ipblocks ORDER BY ipb_timestamp DESC 1 3.154 3.154 0.017% query: SELECT ss_total_views, ss_total_edits, ss_good_articles FROM site_stats WHERE ss_row_id=N 1 2.821 2.821 0.015% Parser::replaceVariables 23 1667.007 72.479 8.924% Skin::makeKnownLinkObj 11 78.723 7.157 0.421% Parser::removeHTMLtags 11 967.015 87.910 5.177% Parser::replaceExternalLinks 11 834.002 75.818 4.465% Tokenizer::newFromString 11 1.106 0.101 0.006% Tokenizer::nextToken 515 2178.971 4.231 11.665% Parser::doTokenizedParser 11 6244.491 567.681 33.430% Parser::internalParse 11 9898.868 899.897 52.993% Tokenizer::previewToken 77 907.472 11.785 4.858% Parser::handleInternalLink-setup 76 91.747 1.207 0.491% Skin::makeBrokenLinkObj 66 498.221 7.549 2.667% Parser::handleInternalLink 76 2936.097 38.633 15.718% query: SELECT iw_url,iw_local FROM interwiki WHERE iw_prefix='X' 19 68.339 3.597 0.366% Parser::doBlockLevels 1 275.380 275.380 1.474% Parser::parse 1 9654.641 9654.641 51.686% query: COMMIT 1 2.466 2.466 0.013% Skin::initPage 1 0.138 0.138 0.001% query: SELECT user_id FROM user WHERE user_name='X' 1 3.091 3.091 0.017% OutputPage::output 1 3084.061 3084.061 16.510% -total 1 18679.445 18679.445 100.000% -overhead-internal 1420 290.628 0.205 1.556% -overhead-total 1420 503.077 0.354 2.693% Total: 18.6794450283