droidwiki / operations-mediawiki-config

MediaWiki configuration of droidwiki.org and some other wikis.
https://www.droidwiki.org
MIT License
2 stars 0 forks source link

Subsequent requests very slow after editing/purging a page #1

Closed FlorianSW closed 6 years ago

FlorianSW commented 6 years ago

Since some time now, whenever you edit a page, subsequent requests to the server (the page again, another page or requests to load.php) will be way slower than usual and expected from the requests made before editing the page. After some time (half a minute up to one minute or so), requests will start performing normally again, without any problems.

I'm not sure, where the problem is located, so this obviously needs some investigation if it's related to the MediaWiki config, MediaWiki itself or the configuration of the server.

FlorianSW commented 6 years ago

Here're some profiling results:

Request which performs normally:

100.00% 168.753      1 - main()
 92.23% 155.635      1 - MediaWiki::run
 92.06% 155.354      1 - MediaWiki::main
 61.89% 104.439      1 - MediaWiki::{closure}
 61.89% 104.435      1 - OutputPage::output
 56.44% 95.236      1 - SkinTemplate::outputPage
 41.43% 69.919      1 - SkinTemplate::prepareQuickTemplate
 28.90% 48.776    282 - Hooks::callHook
 21.28% 35.914      1 - MediaWiki::performRequest
 20.96% 35.374      1 - MediaWiki::performAction
 20.39% 34.404      1 - ViewAction::show
 19.79% 33.403    268 - Message::toString
 18.39% 31.035   1154 - Hooks::run
 16.65% 28.092      1 - Article::view
 14.87% 25.091    201 - Message::text
 14.34% 24.201     78 - Monolog\Logger::addRecord
 13.28% 22.418      1 - VectorTemplate::execute
 13.12% 22.135     26 - Wikimedia\Rdbms\Database::select
 12.45% 21.003     28 - Wikimedia\Rdbms\Database::query
 12.26% 20.694    131 - Monolog\Handler\AbstractProcessingHandler::handle
 11.94% 20.149     12 - Hooks::runWithoutAbort
 11.54% 19.466    402 - Message::fetchMessage
 11.36% 19.165     31 - Wikimedia\Rdbms\Database::doProfiledQuery
 11.33% 19.112     65 - Monolog\Logger::debug
 10.87% 18.340    320 - MessageCache::get
  9.93% 16.752    230 - Message::transformText
  9.88% 16.666     41 - VectorTemplate::makeListItem
  9.73% 16.423     41 - BaseTemplate::makeListItem
  9.56% 16.134    242 - MessageCache::transform
  9.43% 15.912     41 - VectorTemplate::makeLink
  9.39% 15.840     41 - BaseTemplate::makeLink
  9.22% 15.551    320 - MessageCache::getMessageFromFallbackChain
  9.05% 15.266      9 - WikiPage::getContentHandler
  9.03% 15.230    365 - MessageCache::getMessageForLang
  8.93% 15.069      1 - Skin::bottomScripts
  8.89% 15.010      1 - OutputPage::getBottomScripts
  8.82% 14.891      3 - OutputPage::getRlClient
  8.69% 14.672      9 - WikiPage::getContentModel
  8.48% 14.303      7 - Action::factory
  8.40% 14.167      7 - WikiPage::getActionOverrides
  8.35% 14.090      3 - VectorTemplate::renderNavigation
  8.15% 13.754      6 - Action::getActionName
  7.90% 13.329      1 - OutputPage::headElement
  7.71% 13.004      1 - section.Setup.php
  7.47% 12.610     16 - Parser::transformMsg
  7.45% 12.573     16 - Parser::preprocess
  7.24% 12.210     49 - Linker::titleAttrib
  7.02% 11.840     45 - Linker::tooltipAndAccesskeyAttribs
  6.69% 11.296      1 - SkinTemplate::buildPersonalUrls
  6.42% 10.833     33 - MemcachedClient::_load_items
  6.35% 10.718     23 - MemcachedPhpBagOStuff::getMulti
  6.28% 10.596    141 - call_user_func_array
  6.26% 10.571     23 - MemcachedClient::get_multi
  6.18% 10.428    227 - BagOStuff::get
  6.13% 10.351     20 - WANObjectCache::getMulti
  5.89% 9.939    126 - Message::exists
  5.80% 9.794      3 - MediaWiki::getAction
  5.71% 9.628      2 - OutputPage::setPageTitle
  5.68% 9.587     19 - WANObjectCache::get
  5.49% 9.258     69 - MemcachedClient::_fgets
  5.46% 9.222      1 - EchoHooks::onPersonalUrls
  5.46% 9.218     24 - WANObjectCache::getWithSetCallback
  5.34% 9.016      2 - OutputPage::setHTMLTitle
  5.33% 8.997     16 - WANObjectCache::doGetWithSetCallback
  5.25% 8.855    149 - LCStoreCDB::get
  5.24% 8.842     69 - fgets
  5.12% 8.642      1 - OutputPage::addParserOutput
  4.99% 8.418     20 - Parser::replaceVariables
  4.98% 8.400    514 - LocalisationCache::getSubitem
  4.92% 8.303    353 - Language::getMessage
  4.73% 7.986     11 - WikiPage::exists
  4.73% 7.976      1 - WikiPage::loadPageData
  4.72% 7.958     78 - Monolog\Formatter\LineFormatter::format
  4.71% 7.952    149 - Cdb\Reader\PHP::get
  4.70% 7.929    133 - LocalisationCache::loadSubitem
  4.43% 7.473    149 - Cdb\Reader\PHP::find
  4.33% 7.308    437 - spl_autoload_call
  4.32% 7.288      2 - ResourceLoader::__construct
  4.24% 7.155     39 - Wikimedia\Rdbms\LoadBalancer::getConnection
  4.13% 6.976    492 - MediaWiki\Services\ServiceContainer::getService
  4.10% 6.915      1 - ResourceLoaderClientHtml::getHeadHtml
  3.96% 6.685     24 - MediaWiki\Services\ServiceContainer::createService
  3.95% 6.673      1 - VectorTemplate::renderPortals
  3.72% 6.286      1 - OutputPage::checkLastModified
  3.72% 6.284      1 - PageImages::onBeforePageDisplay
  3.70% 6.250     53 - Monolog\Handler\RedisHandler::write
  3.62% 6.106     53 - Redis::rPush
  3.61% 6.086     13 - Title::getUserPermissionsErrorsInternal
  3.51% 5.920    120 - ResourceLoader::register
  3.50% 5.905     11 - Title::userCan
  3.45% 5.827    460 - AutoLoader::autoload
  3.44% 5.808      1 - EchoHooks::onOutputPageCheckLastModified
  3.40% 5.730     18 - Linker::link
  3.35% 5.660    132 - array_map
  3.35% 5.646    131 - Monolog\Formatter\NormalizerFormatter::format
  3.28% 5.540     17 - MWEchoNotifUser::getMemcKey
  3.28% 5.534      4 - VectorTemplate::renderPortal
  3.24% 5.462    131 - Monolog\Formatter\NormalizerFormatter::normalize
  3.23% 5.455      4 - Message::parseText
  3.21% 5.420     40 - Wikimedia\Rdbms\LoadBalancer::getReaderIndex
  3.18% 5.365      4 - Wikimedia\Rdbms\Database::selectRow
  3.17% 5.356      7 - MWEchoNotifUser::getGlobalMemcKey
  3.15% 5.309     33 - Wikimedia\Rdbms\DatabaseMysqli::doQuery
  3.14% 5.304      1 - Skin::getCategories
  3.11% 5.240      2 - MWEchoNotifUser::getNotificationCount
  3.10% 5.225      1 - Skin::getCategoryLinks
  3.09% 5.215      4 - MessageCache::parse
  3.09% 5.209     21 - MediaWiki\Services\ServiceContainer::{closure}
  3.09% 5.208      1 - MWEchoNotifUser::getMessageCount
  3.05% 5.155      4 - MWEchoNotifUser::getFromCache
  3.05% 5.139      1 - OutputPage::addParserOutputText
  3.00% 5.056      7 - CentralIdLookup::centralIdFromLocalUser
  2.98% 5.032      1 - ResourceLoaderClientHtml::getData
  2.96% 5.001     33 - mysqli::query
  2.95% 4.981      7 - CentralIdLookup::centralIdFromName
  2.94% 4.969      7 - LocalIdLookup::lookupUserNames
  2.93% 4.951      2 - ResourceLoaderWikiModule::preloadTitleInfo
  2.91% 4.915     20 - PPFrame_DOM::expand
  2.89% 4.874    303 - preg_replace_callback
  2.86% 4.831      5 - ParserOutput::getText
  2.86% 4.821     12 - Monolog\Logger::info
  2.77% 4.671      1 - MediaWiki::doPreOutputCommit
  2.77% 4.668      1 - MediaWiki::preOutputCommit
  2.74% 4.627      1 - section.Setup.php-globals
  2.74% 4.625    363 - MessageCache::getMsgFromNamespace
  2.73% 4.613      1 - OutputPage::getJSVars
  2.66% 4.481      1 - SkinTemplate::buildContentNavigationUrls
  2.65% 4.478    917 - Monolog\Formatter\NormalizerFormatter::normalize@1
  2.65% 4.477      7 - ParserOutput::{closure}
  2.64% 4.459      7 - MemcachedBagOStuff::doGet
  2.63% 4.445      7 - MemcachedBagOStuff::getWithToken
  2.62% 4.417      4 - EchoSeenTime::getTime
  2.61% 4.411      7 - MemcachedClient::get
  2.60% 4.391      6 - OutputPage::getRlClientContext
  2.56% 4.316      1 - MWEchoNotifUser::getPreloadKeys
  2.51% 4.233     11 - Title::isKnown
  2.51% 4.231     10 - OutputPage::getResourceLoader
  2.50% 4.223      1 - MWEchoNotifUser::getGlobalKeys
  2.50% 4.221      7 - CachedBagOStuff::doGet
  2.48% 4.183     40 - Wikimedia\Rdbms\LoadBalancer::openConnection
  2.48% 4.178      7 - Skin::doEditSectionLink
  2.47% 4.175      4 - Parser::parse
  2.46% 4.156     78 - Title::newFromText
  2.43% 4.109      9 - wfDebugLog
  2.41% 4.064      1 - Wikimedia\Rdbms\LoadBalancer::pickReaderIndex
  2.40% 4.053      4 - MediaWiki\Linker\LinkRenderer::makeLink
  2.39% 4.040     78 - Title::newFromTextThrow
  2.38% 4.014     73 - Title::secureAndSplit
  2.37% 3.999     53 - Monolog\Formatter\LogstashFormatter::format
  2.36% 3.987     79 - call_user_func_array@1
  2.36% 3.978      9 - WebRequest::getSession
  2.35% 3.974      1 - Skin::getUndeleteLink
  2.34% 3.957    148 - User::load
  2.33% 3.924      4 - Wikimedia\Rdbms\Database::selectField
  2.32% 3.915    958 - Cdb\Reader\PHP::readInt32
  2.22% 3.741     20 - Parser::startParse
  2.20% 3.721      3 - ReplicatedBagOStuff::doGet
  2.20% 3.712      3 - BagOStuff::get@1
  2.19% 3.700      3 - SqlBagOStuff::doGet
  2.19% 3.695      3 - SqlBagOStuff::getWithToken
  2.19% 3.689    477 - htmlspecialchars
  2.18% 3.687      3 - SqlBagOStuff::getMulti
  2.18% 3.674      1 - ExtensionRegistry::loadFromQueue
  2.18% 3.671      1 - Skin::buildSidebar
  2.15% 3.622      1 - Skin::{closure}
  2.14% 3.613      1 - Skin::addToSidebar
  2.14% 3.612     20 - Parser::clearState
  2.12% 3.584     19 - Parser::braceSubstitution
  2.12% 3.572      1 - Skin::addToSidebarPlain
  2.08% 3.518    363 - MessageCache::load
  2.08% 3.512      2 - MediaWiki\Session\SessionManager::getSessionForRequest
  2.07% 3.498      1 - OutputPage::addParserOutputMetadata
  2.05% 3.459     24 - Parser::preprocessToDom
  2.04% 3.447      1 - File::transform
  2.02% 3.413      2 - Message::__toString
  2.02% 3.412     24 - Preprocessor_DOM::preprocessToObj
  1.97% 3.320     25 - wfDebug
  1.95% 3.298      1 - section.Setup.php-session
  1.90% 3.210   1162 - Cdb\Reader\PHP::read
  1.89% 3.194     90 - Linker::accesskey
  1.89% 3.193      2 - MediaWiki\Session\SessionManager::getSessionInfoForRequest
  1.88% 3.167      1 - ResourceLoaderContext::newDummyContext
  1.87% 3.156      1 - ParserCache::get
  1.87% 3.152      6 - ResourceLoaderWikiModule::isKnownEmpty
  1.85% 3.121      6 - ResourceLoaderWikiModule::getTitleInfo
  1.79% 3.025     11 - Title::isAlwaysKnown
  1.76% 2.967      1 - DeferredUpdates::doUpdates
  1.76% 2.964      1 - DeferredUpdates::execute
  1.74% 2.934    111 - fwrite
  1.72% 2.903      1 - DeferredUpdates::runUpdate
  1.70% 2.869    468 - Monolog\Formatter\LineFormatter::stringify
  1.70% 2.866     20 - MediaWiki\Linker\LinkRenderer::makeKnownLink
  1.69% 2.858      4 - Parser::internalParse
  1.69% 2.849      1 - SkinVector::initPage
  1.69% 2.845      3 - MediaWiki\Session\SessionManager::getGlobalSession
  1.68% 2.840      8 - SpecialPageFactory::resolveAlias
  1.68% 2.838     11 - TranslateHooks::onTitleIsAlwaysKnown
  1.68% 2.832      1 - Skin::initPage
  1.68% 2.830      1 - Skin::preloadExistence
  1.67% 2.811     73 - MediaWikiTitleCodec::splitTitleString
  1.64% 2.772      1 - PageImages::getPageImage
  1.64% 2.772      1 - File::thumbName
  1.64% 2.767      1 - File::generateThumbName
  1.64% 2.765     29 - SpecialPageFactory::getAliasList
  1.63% 2.753     68 - User::loadOptions
  1.63% 2.748     30 - Wikimedia\Rdbms\LBFactory::Wikimedia\Rdbms\{closure}
  1.62% 2.737     20 - MessageCache::getParser
  1.62% 2.736      1 - MediaHandler::getThumbType
  1.61% 2.722      1 - MediaWiki\MediaWikiServices::getMimeAnalyzer
  1.61% 2.711    351 - call_user_func
  1.59% 2.681      1 - StubObject::firstCallInit
  1.59% 2.680      1 - StubObject::__call
  1.59% 2.678      1 - StubObject::_call
  1.58% 2.665    159 - Html::rawElement
  1.57% 2.641      1 - MimeAnalyzer::__construct
  1.56% 2.637      1 - MimeAnalyzer::loadFiles
  1.54% 2.596     29 - Message::escaped
  1.44% 2.426    169 - Html::openElement
  1.42% 2.391     27 - call_user_func_array@2
  1.41% 2.371      2 - Message::parse
  1.40% 2.365     66 - User::getOption
  1.40% 2.363      1 - OutputPage::addCategoryLinks
  1.38% 2.324     20 - Wikibase\Client\Hooks\ParserClearStateHookHandler::onParserClearState
  1.37% 2.312      3 - SkinTemplate::tabAction
  1.37% 2.311     26 - Wikimedia\Rdbms\Database::selectSQLText
  1.37% 2.306      1 - ParserCache::getKey
  1.36% 2.299    730 - Cdb\Reader\PHP::readInt31
  1.34% 2.264      2 - ResourceLoaderWikiModule::fetchTitleInfo
  1.34% 2.261      3 - ResourceLoaderUserStylesModule::getPages
  1.33% 2.251      1 - Parser::firstCallInit
  1.30% 2.202     20 - Wikibase\Client\WikibaseClient::getRestrictedEntityLookup
  1.30% 2.196      1 - Skin::lastModified
  1.30% 2.190      1 - LinkBatch::execute
  1.29% 2.183      1 - LinkBatch::executeInto
  1.28% 2.159     75 - Title::getLocalURL
  1.28% 2.156     35 - MediaWiki\Services\ServiceContainer::getService@1
  1.27% 2.144     83 - User::isLoggedIn
  1.27% 2.140     33 - MemcachedClient::_fwrite
  1.26% 2.134     61 - User::isAnon
  1.26% 2.133     25 - Language::getMessageFromDB
  1.26% 2.133      1 - MWCallableUpdate::doUpdate
  1.26% 2.131      1 - WikiPage::{closure}
  1.26% 2.130    136 - User::getId
  1.26% 2.125     16 - MediaWiki\Services\ServiceContainer::createService@1
  1.26% 2.123      1 - User::clearNotification
  1.24% 2.095      2 - Wikimedia\Rdbms\LoadBalancer::reallyOpenConnection
  1.23% 2.073      3 - Wikimedia\Rdbms\Database::begin
  1.21% 2.048     20 - MediaWiki\Linker\LinkRenderer::makePreloadedLink
  1.18% 1.986     10 - Title::quickUserCan
  1.18% 1.983     14 - Title::checkUserBlock
  1.17% 1.976      1 - Wikibase\Client\WikibaseClient::getEntityLookup
  1.17% 1.970      1 - User::isBlocked
  1.17% 1.968     26 - Wikimedia\Rdbms\LBFactoryMulti::forEachLB
  1.17% 1.968      1 - User::getBlock
  1.17% 1.967      9 - ResourceLoaderClientHtml::makeLoad
  1.17% 1.966      1 - User::getBlockedStatus
  1.16% 1.960    708 - Language::caseFold
  1.16% 1.956      3 - Wikimedia\Rdbms\LBFactory::commitMasterChanges
  1.15% 1.942      1 - WatchedItemStore::resetNotificationTimestamp
  1.14% 1.916     16 - LocalisationCache::loadItem
  1.13% 1.912      3 - Wikimedia\Rdbms\Database::doBegin
  1.13% 1.906      3 - Wikimedia\Rdbms\Database::query@1
  1.12% 1.885      1 - WatchedItemStore::loadWatchedItem
  1.11% 1.880      1 - WikiPage::pageDataFromTitle
  1.11% 1.876    335 - LocalisationCache::getItem
  1.11% 1.873      1 - WikiPage::pageData
  1.08% 1.830     50 - Wikimedia\Rdbms\LoadBalancer::forEachOpenMasterConnection
  1.08% 1.827    149 - Cdb\Util::hash
  1.07% 1.798      2 - Wikimedia\Rdbms\Database::factory
  1.07% 1.798      1 - Block::newFromTarget
  1.04% 1.761      2 - MediaWiki\Session\SessionManager::loadSessionInfoFromStore
  1.04% 1.754      2 - EchoNotificationController::formatNotificationCount
  1.04% 1.751    468 - Monolog\Formatter\LineFormatter::convertToString
  1.03% 1.736      1 - ExtensionRegistry::exportExtractedData
  1.03% 1.735      5 - User::idFromName
  1.01% 1.705     45 - MemcachedClient::get_sock
  1.00% 1.689      1 - OutputPage::getHeadLinksArray
  1.00% 1.685    711 - Language::uc
  0.99% 1.675     31 - LinkCache::addLinkObj
  0.99% 1.672      3 - ResourceLoaderClientHtml::getLoad
  0.99% 1.666    169 - Html::expandAttributes
  0.99% 1.664   1397 - Monolog\Formatter\NormalizerFormatter::normalize@2
  0.97% 1.639      2 - Wikimedia\Rdbms\Database::initConnection
  0.96% 1.619      2 - Wikimedia\Rdbms\Database::doInitConnection
  0.96% 1.612      2 - Wikimedia\Rdbms\DatabaseMysqlBase::open
  0.95% 1.603      8 - User::getEffectiveGroups
  0.93% 1.562    514 - GlobalVarConfig::get
  0.93% 1.561     99 - Wikimedia\Rdbms\LoadBalancer::Wikimedia\Rdbms\{closure}
  0.92% 1.550    209 - Monolog\Formatter\NormalizerFormatter::toJson
  0.92% 1.545      3 - User::getAutomaticGroups
  0.91% 1.535      7 - Wikimedia\Rdbms\LBFactory::forEachLBCallMethod
  0.90% 1.521     45 - ResourceLoaderClientHtml::makeContext
  0.89% 1.494    106 - spl_autoload_call@1
  0.88% 1.490      3 - Autopromote::getAutopromoteGroups
  0.88% 1.485      1 - Skin::subPageSubtitle
  0.87% 1.466     47 - Wikimedia\Timestamp\ConvertibleTimestamp::convert
  0.87% 1.463     43 - wfTimestamp
  0.87% 1.461    310 - wfMessage
  0.86% 1.455      1 - section.Setup.php-extensions
  0.86% 1.443      1 - PageTranslationHooks::translatablePageHeader
  0.85% 1.432      1 - ParserOptions::optionsHash
  0.85% 1.427      6 - Wikibase\Client\WikibaseClient::{closure}
  0.83% 1.409   1930 - ResourceLoader::isFileModule
  0.83% 1.399      4 - Wikibase\DataAccess\MultipleRepositoryAwareWikibaseServices::Wikibase\DataAccess\{closure}
  0.82% 1.388      1 - section.Setup.php-misc1
  0.82% 1.388     24 - Preprocessor_DOM::preprocessToXml
  0.82% 1.386      3 - Wikimedia\Rdbms\LoadBalancer::commitMasterChanges
  0.82% 1.376      7 - VisualEditorHooks::onSkinEditSectionLinks
  0.82% 1.376     30 - Title::exists
  0.81% 1.374     11 - Title::checkQuickPermissions
  0.81% 1.372     40 - ResourceLoaderClientHtml::getContext
  0.81% 1.370     29 - User::isAllowed
  0.81% 1.369     78 - MediaWiki\Logger\Monolog\LegacyHandler::write
  0.81% 1.369      1 - PageTranslationHooks::sourcePageHeader
  0.81% 1.361      1 - Wikimedia\Rdbms\DBConnRef::selectRow
  0.81% 1.361     74 - Hooks::run@1
  0.80% 1.357      1 - Wikimedia\Rdbms\DBConnRef::__call
  0.80% 1.354     45 - MemcachedClient::sock_to_host
  0.80% 1.354     21 - Hooks::callHook@1
  0.80% 1.348      2 - TranslatablePage::getTag
  0.80% 1.346     36 - Title::getLinkURL
  0.80% 1.343      1 - MWEchoNotifUser::getGlobalUpdateTime
  0.80% 1.343      1 - EchoEventMapper::fetchUnreadByUserAndPage
  0.78% 1.312     41 - Title::getArticleID
  0.77% 1.302   1069 - preg_match
  0.77% 1.298      5 - SqlBagOStuff::getDB
  0.77% 1.294      4 - MemcachedClient::_connect_sock
  0.77% 1.293     14 - Wikimedia\Rdbms\Database::commit
  0.77% 1.292    209 - Monolog\Formatter\NormalizerFormatter::jsonEncode
  0.76% 1.289      4 - EchoSeenTime::getMemcKey
  0.76% 1.285     30 - User::getRights
  0.76% 1.283     29 - TranslatablePage::isTranslationPage
  0.76% 1.280      1 - Skin::getNewtalks
  0.76% 1.276      1 - Wikibase\Client\Hooks\SkinTemplateOutputPageBeforeExecHandler::onSkinTemplateOutputPageBeforeExec
  0.76% 1.275     57 - MediaWiki\Logger\LoggerFactory::getInstance
  0.74% 1.257      2 - Wikimedia\Rdbms\Database::doCommit
  0.74% 1.252      2 - MessageCache::getValidationHash
  0.74% 1.248   1243 - Hooks::getHandlers
  0.74% 1.248      2 - MediaWiki\Session\CookieSessionProvider::provideSessionInfo
  0.74% 1.247      2 - User::getNewMessageLinks
  0.74% 1.243      1 - ResourceLoader::makeModuleResponse
  0.74% 1.242     97 - Language::getFallbacksFor
  0.73% 1.239     14 - Title::checkPermissionHooks
  0.73% 1.235      3 - User::getNewtalk
  0.73% 1.234      8 - APCBagOStuff::doGet
  0.73% 1.233     91 - ContextSource::msg
  0.73% 1.229      1 - wfFindFile
  0.73% 1.225      1 - User::checkNewtalk
  0.72% 1.223      2 - Wikibase\Client\Store\Sql\DirectSqlStore::getEntityLookup
  0.72% 1.222     66 - MemcachedBagOStuff::makeKeyInternal
  0.72% 1.215     13 - Language::getMonthName
  0.72% 1.210      4 - fsockopen
  0.71% 1.205      8 - apc_fetch
  0.71% 1.198      1 - Wikibase\Client\Hooks\SkinTemplateOutputPageBeforeExecHandler::doSkinTemplateOutputPageBeforeExec
  0.71% 1.195     97 - Parser::setFunctionHook
  0.70% 1.189      2 - Wikibase\DataAccess\MultiRepositoryServices::getServiceMap
  0.70% 1.189     11 - Parser::callParserFunction
  0.70% 1.187      2 - Wikibase\Client\Store\Sql\DirectSqlStore::getEntityRevisionLookup
  0.70% 1.183      1 - Wikibase\Client\Store\Sql\DirectSqlStore::newEntityRevisionLookup
  0.70% 1.180    659 - is_callable
  0.70% 1.179      1 - RepoGroup::findFile
  0.70% 1.176      1 - BaseTemplate::makeSearchInput
  0.69% 1.164     49 - Wikimedia\Timestamp\ConvertibleTimestamp::__construct
  0.67% 1.138    100 - Composer\Autoload\ClassLoader::loadClass
  0.67% 1.131      1 - Wikibase\DataAccess\MultipleRepositoryAwareWikibaseServices::getEntityRevisionLookup
  0.67% 1.127      1 - OutputPage::addCategoryLinksToLBAndGetResult
  0.67% 1.123      1 - Wikibase\DataAccess\MultiRepositoryServices::getEntityRevisionLookup
  0.66% 1.122      1 - BaseTemplate::getToolbox
  0.66% 1.122      1 - Language::getMonthNamesArray
  0.66% 1.116      1 - SkinTemplate::wrapHTML
  0.66% 1.110     20 - PageTranslationHooks::renderTagPage
  0.66% 1.108     49 - Wikimedia\Timestamp\ConvertibleTimestamp::setTimestamp
  0.64% 1.074     47 - ResourceLoaderContext::__construct
  0.63% 1.069      2 - MediaWiki\MediaWikiServices::newInstance
  0.63% 1.065      2 - TimedMediaHandlerHooks::activePlayerMode
  0.63% 1.064     57 - MediaWiki\Logger\MonologSpi::getLogger
  0.63% 1.060      1 - TimedMediaHandlerHooks::changePageRenderingHash
  0.62% 1.051    152 - MediaWikiTitleCodec::getNamespaceName
  0.62% 1.050      1 - SkinTemplate::buildNavUrls
  0.62% 1.047   1930 - ResourceLoader::isValidModuleName
  0.61% 1.034      1 - LinkBatch::doQuery
  0.61% 1.029     18 - MediaWiki\Services\ServiceContainer::getService@2
  0.61% 1.027      5 - Language::factory
  0.60% 1.017      2 - BetaFeatures::isFeatureEnabled
  0.60% 1.016    293 - fread
  0.60% 1.014      1 - Wikibase\ClientHooks::onBaseTemplateToolbox
  0.60% 1.014     55 - BagOStuff::makeKey
  0.60% 1.011      6 - User::newFromName
  0.60% 1.010      6 - MediaWiki\Services\ServiceContainer::createService@2
  0.60% 1.008      3 - AbuseFilterHooks::onGetAutoPromoteGroups
  0.60% 1.007     89 - AutoLoader::autoload@1
  0.60% 1.006     13 - MediaWiki\Services\ServiceContainer::applyWiring

Request which performs very slow:

100.00% 5564.627      1 - main()
 95.81% 5331.349     20 - WANObjectCache::getWithSetCallback
 95.80% 5331.106     13 - WANObjectCache::doGetWithSetCallback
 95.68% 5324.207      1 - section.Setup.php
 95.48% 5313.132      1 - section.Setup.php-globals
 95.46% 5312.161      9 - WebRequest::getSession
 95.46% 5311.982    247 - User::load
 95.46% 5311.812      1 - section.Setup.php-session
 95.45% 5311.629      2 - MediaWiki\Session\SessionManager::getSessionForRequest
 95.45% 5311.327      2 - MediaWiki\Session\SessionManager::getSessionInfoForRequest
 95.45% 5311.276      3 - MediaWiki\Session\SessionManager::getGlobalSession
 95.43% 5310.447      2 - MediaWiki\Session\CookieSessionProvider::provideSessionInfo
 95.43% 5310.220      2 - MediaWiki\Session\UserInfo::newFromId
 95.43% 5310.203      6 - User::loadFromId
 95.43% 5310.168      6 - User::loadFromCache
 95.42% 5309.768      1 - WANObjectCache::{closure}
 95.42% 5309.762      1 - User::{closure}
 95.41% 5308.969     52 - Wikimedia\Rdbms\LoadBalancer::getConnection
 95.21% 5298.243     36 - wfGetDB
 95.20% 5297.247     55 - Wikimedia\Rdbms\LoadBalancer::getReaderIndex
 95.15% 5294.998     54 - Wikimedia\Rdbms\LoadBalancer::openConnection
 95.15% 5294.922     30 - Wikimedia\Rdbms\LBFactory::Wikimedia\Rdbms\{closure}
 95.15% 5294.833    468 - call_user_func
 95.14% 5294.087      1 - Wikimedia\Rdbms\LoadBalancer::pickReaderIndex
 95.04% 5288.828      1 - Wikimedia\Rdbms\ChronologyProtector::initLB
 95.04% 5288.812      1 - Wikimedia\Rdbms\ChronologyProtector::initPositions
 95.03% 5287.992      3 - Wikimedia\WaitConditionLoop::invoke
 94.96% 5284.346     32 - Wikimedia\WaitConditionLoop::usleep
 94.95% 5283.878     32 - usleep
  4.32% 240.309      1 - MediaWiki::run
  4.31% 239.994      1 - MediaWiki::main
  2.68% 149.393      1 - MediaWiki::{closure}
  2.68% 149.389      1 - OutputPage::output
  2.44% 135.963      1 - SkinTemplate::outputPage
  2.00% 111.229      1 - SkinTemplate::prepareQuickTemplate
  1.55% 86.449     42 - Wikimedia\Rdbms\Database::query
  1.49% 82.799     45 - Wikimedia\Rdbms\Database::doProfiledQuery
  1.40% 78.015     38 - Wikimedia\Rdbms\Database::select
  1.36% 75.720    205 - Hooks::callHook
  1.29% 72.052      1 - MediaWiki::performRequest
  1.28% 71.495      1 - MediaWiki::performAction
  1.27% 70.899      1 - ViewAction::show
  1.15% 63.924      1 - Article::view
  1.12% 62.569     96 - Monolog\Logger::addRecord
  1.03% 57.045    226 - Message::toString
  0.98% 54.472    167 - Monolog\Handler\AbstractProcessingHandler::handle
  0.94% 52.465     79 - Monolog\Logger::debug
  0.85% 47.539     12 - Hooks::runWithoutAbort
  0.84% 46.664    175 - Message::text
  0.82% 45.744    331 - Message::fetchMessage
  0.80% 44.716    249 - MessageCache::get
  0.75% 41.760    249 - MessageCache::getMessageFromFallbackChain
  0.75% 41.486    265 - MessageCache::getMessageForLang
  0.62% 34.417     47 - Wikimedia\Rdbms\DatabaseMysqli::doQuery
  0.61% 33.724     47 - mysqli::query
  0.57% 31.748    263 - MessageCache::getMsgFromNamespace
  0.56% 30.957    929 - Hooks::run
  0.55% 30.619    263 - MessageCache::load
  0.54% 30.179      1 - SkinTemplate::buildPersonalUrls
  0.53% 29.608      2 - OutputPage::setPageTitle
  0.52% 28.693      3 - OutputPage::setHTMLTitle
  0.49% 27.517     71 - Monolog\Handler\RedisHandler::write
  0.49% 27.250      1 - EchoHooks::onPersonalUrls
  0.49% 27.155     71 - Redis::rPush
  0.48% 26.768      2 - MessageCache::loadFromDBWithLock
  0.41% 22.623    156 - call_user_func_array
  0.40% 22.130      1 - Skin::bottomScripts
  0.40% 22.051      1 - OutputPage::getBottomScripts
  0.39% 21.876      3 - OutputPage::getRlClient
  0.33% 18.233      1 - VectorTemplate::execute
  0.31% 17.238      2 - MWEchoNotifUser::getNotificationCount
  0.30% 16.873    189 - Message::transformText
  0.30% 16.696    214 - BagOStuff::get
  0.30% 16.436      2 - MessageCache::loadFromDB
  0.29% 16.244    195 - MessageCache::transform
  0.29% 15.990    100 - Wikimedia\Rdbms\LoadBalancer::Wikimedia\Rdbms\{closure}
  0.28% 15.701     95 - Message::exists
  0.27% 14.828      1 - SkinTemplate::buildContentNavigationUrls
  0.27% 14.783      1 - MWEchoNotifUser::getMessageCount
  0.26% 14.485     34 - VectorTemplate::makeListItem
  0.26% 14.287     34 - BaseTemplate::makeListItem
  0.25% 13.858     34 - VectorTemplate::makeLink
  0.25% 13.823      3 - WANObjectCache::getWithSetCallback@1
  0.25% 13.809      3 - WANObjectCache::doGetWithSetCallback@1
  0.25% 13.785     34 - BaseTemplate::makeLink
  0.25% 13.778      3 - VectorTemplate::renderNavigation
  0.25% 13.679     96 - Monolog\Formatter\LineFormatter::format
  0.23% 12.787      3 - Wikimedia\Rdbms\Database::selectField
  0.22% 12.083      1 - OutputPage::headElement
  0.21% 11.773      6 - Wikimedia\Rdbms\Database::selectRow
  0.21% 11.485      2 - wfReadOnly
  0.21% 11.477      3 - ReadOnlyMode::isReadOnly
  0.21% 11.472      3 - ReadOnlyMode::getReason
  0.21% 11.464      1 - MediaWiki::doPreOutputCommit
  0.21% 11.460      1 - MediaWiki::preOutputCommit
  0.21% 11.422      3 - Wikimedia\Rdbms\LoadBalancer::getReadOnlyReason
  0.20% 11.400      1 - WikiPage::doViewUpdates
  0.20% 11.355     17 - MWEchoNotifUser::getMemcKey
  0.20% 11.256      3 - Wikimedia\Rdbms\LoadBalancer::masterRunningReadOnly
  0.20% 11.040      7 - MWEchoNotifUser::getGlobalMemcKey
  0.20% 10.974     13 - Title::getUserPermissionsErrorsInternal
  0.20% 10.882      3 - SkinTemplate::tabAction
  0.19% 10.801    432 - spl_autoload_call
  0.19% 10.762     18 - Parser::transformMsg
  0.19% 10.756     11 - Title::userCan
  0.19% 10.739    167 - Monolog\Formatter\NormalizerFormatter::format
  0.19% 10.732      2 - Wikimedia\Rdbms\DatabaseMysqlBase::serverIsReadOnly
  0.19% 10.720     18 - Parser::preprocess
  0.19% 10.693    102 - array_map
  0.19% 10.666      7 - CentralIdLookup::centralIdFromLocalUser
  0.19% 10.598     20 - MemcachedClient::_fgets
  0.19% 10.554      7 - CentralIdLookup::centralIdFromName
  0.19% 10.537      7 - LocalIdLookup::lookupUserNames
  0.19% 10.475    167 - Monolog\Formatter\NormalizerFormatter::normalize
  0.19% 10.416     20 - fgets
  0.18% 10.084     75 - call_user_func_array@1
  0.18% 10.030      4 - MWEchoNotifUser::getFromCache
  0.18% 9.963      2 - ResourceLoader::__construct
  0.18% 9.866     22 - Parser::replaceVariables
  0.18% 9.798      1 - MWEchoNotifUser::getPreloadKeys
  0.17% 9.667      1 - MWEchoNotifUser::getGlobalKeys
  0.17% 9.605     40 - Linker::titleAttrib
  0.17% 9.503     38 - Linker::tooltipAndAccesskeyAttribs
  0.16% 9.053     15 - Monolog\Logger::info
  0.16% 8.981      4 - Message::parseText
  0.16% 8.961      1 - Wikimedia\Rdbms\LoadBalancer::getReadOnlyReason@1
  0.16% 8.927      1 - Wikimedia\Rdbms\LoadBalancer::masterRunningReadOnly@1
  0.16% 8.768      1 - Wikimedia\Rdbms\LoadBalancer::Wikimedia\Rdbms\{closure}@1
  0.16% 8.733    111 - LCStoreCDB::get
  0.16% 8.678    104 - User::loadOptions
  0.16% 8.652      4 - MessageCache::parse
  0.15% 8.585   1169 - Monolog\Formatter\NormalizerFormatter::normalize@1
  0.15% 8.543     71 - Monolog\Formatter\LogstashFormatter::format
  0.15% 8.271    456 - AutoLoader::autoload
  0.15% 8.200      1 - DeferredUpdates::doUpdates
  0.15% 8.195      1 - DeferredUpdates::execute
  0.15% 8.182      8 - MemcachedBagOStuff::doGet
  0.15% 8.165    413 - LocalisationCache::getSubitem
  0.15% 8.157      8 - MemcachedBagOStuff::getWithToken
  0.15% 8.156    118 - ResourceLoader::register
  0.15% 8.097      1 - Skin::getUndeleteLink
  0.15% 8.083      1 - DeferredUpdates::runUpdate
  0.14% 8.062      8 - MemcachedClient::get
  0.14% 7.790    258 - Language::getMessage
  0.14% 7.684     95 - LocalisationCache::loadSubitem
  0.14% 7.609      2 - ResourceLoaderWikiModule::preloadTitleInfo
  0.14% 7.607    111 - Cdb\Reader\PHP::get
  0.14% 7.597     33 - call_user_func_array@2
  0.14% 7.558     12 - wfDebugLog
  0.13% 7.417      4 - Parser::parse
  0.13% 7.268      7 - WikiPage::getContentHandler
  0.13% 7.191      5 - OutputPage::getRlClientContext
  0.13% 7.154    432 - MediaWiki\Services\ServiceContainer::getService
  0.13% 7.150    111 - Cdb\Reader\PHP::find
  0.13% 7.105      5 - Action::factory
  0.13% 7.088      4 - Action::getActionName
  0.13% 7.059     40 - Wikimedia\Rdbms\Database::selectSQLText
  0.13% 7.004      5 - WikiPage::getActionOverrides
  0.13% 6.997     82 - Title::newFromText
  0.12% 6.943      1 - OutputPage::checkLastModified
  0.12% 6.923      9 - OutputPage::getResourceLoader
  0.12% 6.838      8 - WikiPage::{closure}
  0.12% 6.831     82 - Title::newFromTextThrow
  0.12% 6.745      1 - OutputPage::addParserOutput
  0.12% 6.727     20 - MediaWiki\Services\ServiceContainer::createService
  0.12% 6.707      7 - WikiPage::getContentModel
  0.12% 6.638     11 - SpecialPage::getTitleFor
  0.12% 6.575      1 - EchoHooks::onOutputPageCheckLastModified
  0.12% 6.477     54 - Title::secureAndSplit
  0.12% 6.451      1 - SkinVector::initPage
  0.12% 6.422      1 - Skin::initPage
  0.12% 6.420      1 - Skin::preloadExistence
  0.12% 6.414      3 - MediaWiki::getAction
  0.11% 6.368      1 - ResourceLoaderClientHtml::getHeadHtml
  0.11% 6.333      2 - EchoUserNotificationGateway::getCappedNotificationCount
  0.11% 6.302     11 - SpecialPage::getTitleValueFor
  0.11% 6.290      8 - MemcachedClient::_load_items
  0.11% 6.257      3 - ResourceLoaderWikiModule::fetchTitleInfo
  0.11% 6.209      2 - Wikimedia\Rdbms\Database::selectRowCount
  0.11% 6.114      1 - Article::showViewFooter
  0.11% 6.094      1 - Article::showPatrolFooter
  0.11% 6.047     20 - SpecialPageFactory::getLocalNameFor
  0.11% 6.006      1 - GoogleSiteLinksSearchBox\Hooks::onBeforePageDisplay
  0.11% 6.003      4 - Parser::internalParse
  0.11% 5.884     26 - Wikimedia\Rdbms\LBFactoryMulti::forEachLB
  0.11% 5.875      3 - Wikimedia\Rdbms\LBFactory::commitMasterChanges
  0.11% 5.861      1 - OutputPage::getJSVars
  0.10% 5.817      1 - OutputPage::addParserOutputText
  0.10% 5.723     14 - Title::checkUserBlock
  0.10% 5.704      1 - User::isBlocked
  0.10% 5.701      1 - User::getBlock
  0.10% 5.698      1 - User::getBlockedStatus
  0.10% 5.642     22 - PPFrame_DOM::expand
  0.10% 5.504      3 - ReplicatedBagOStuff::doGet
  0.10% 5.496      3 - BagOStuff::get@1
  0.10% 5.477     50 - Wikimedia\Rdbms\LoadBalancer::forEachOpenMasterConnection
  0.10% 5.462      3 - SqlBagOStuff::doGet
  0.10% 5.454      3 - SqlBagOStuff::getWithToken
  0.10% 5.444      3 - SqlBagOStuff::getMulti
  0.10% 5.411      2 - Message::parse
  0.10% 5.398      4 - BagOStuff::{closure}
  0.09% 5.285      1 - Block::newFromTarget
  0.09% 5.254     40 - Wikimedia\ScopedCallback::__destruct
  0.09% 5.098     54 - MediaWikiTitleCodec::splitTitleString
  0.09% 5.071      7 - Wikimedia\Rdbms\LBFactory::forEachLBCallMethod
  0.09% 5.034      3 - Wikimedia\Rdbms\Database::begin
  0.09% 5.012      2 - ResourceLoaderWikiModule::{closure}
  0.09% 4.991     24 - SpecialPageFactory::getAliasList
  0.09% 4.892      4 - EchoSeenTime::getTime
  0.09% 4.834      2 - BagOStuff::unlock
  0.09% 4.820      2 - MemcachedBagOStuff::delete
  0.09% 4.807      3 - Wikimedia\Rdbms\LoadBalancer::commitMasterChanges
  0.09% 4.807      7 - CachedBagOStuff::doGet
  0.09% 4.797      2 - MemcachedClient::delete
  0.08% 4.689      3 - Wikimedia\Rdbms\Database::doBegin
  0.08% 4.681      3 - Wikimedia\Rdbms\Database::query@1
  0.08% 4.626      1 - MWCallableUpdate::doUpdate
  0.08% 4.604      1 - User::clearNotification
  0.08% 4.594     14 - Wikimedia\Rdbms\Database::commit
  0.08% 4.555     15 - User::getDefaultOptions
  0.08% 4.550      6 - Wikimedia\Rdbms\DBConnRef::__call
  0.08% 4.549     25 - wfDebug
  0.08% 4.540      2 - Wikimedia\Rdbms\DBConnRef::selectRow
  0.08% 4.538      1 - LinkBatch::execute
  0.08% 4.531      2 - Wikimedia\Rdbms\Database::doCommit
  0.08% 4.529    576 - Monolog\Formatter\LineFormatter::stringify
  0.08% 4.525      1 - LinkBatch::executeInto
  0.08% 4.514     22 - MessageCache::getParser
  0.08% 4.499     25 - MediaWiki\Services\ServiceContainer::getService@1
  0.08% 4.461     12 - MediaWiki\Services\ServiceContainer::createService@1
  0.08% 4.420      1 - StubObject::firstCallInit
  0.08% 4.418      1 - StubObject::__call
  0.08% 4.415      1 - StubObject::_call
  0.08% 4.351      1 - ParserCache::get
  0.08% 4.317      1 - PageImages::onBeforePageDisplay
  0.08% 4.309      1 - PageImages::getPageImage
  0.08% 4.294    706 - Language::caseFold
  0.08% 4.202      1 - EchoEventMapper::fetchUnreadByUserAndPage
  0.08% 4.201      1 - WatchedItemStore::resetNotificationTimestamp
  0.07% 4.126    371 - htmlspecialchars
  0.07% 4.119      1 - WatchedItemStore::loadWatchedItem
  0.07% 4.112     26 - Parser::preprocessToDom
  0.07% 4.074      1 - Wikibase\Repo\Hooks\OutputPageBeforeHTMLHookHandler::onOutputPageBeforeHTML
  0.07% 4.059      1 - Wikibase\Repo\Hooks\OutputPageBeforeHTMLHookHandler::newFromGlobalState
  0.07% 4.050     21 - Parser::braceSubstitution
  0.07% 4.044     26 - Preprocessor_DOM::preprocessToObj
  0.07% 3.973      2 - Wikimedia\Rdbms\LoadBalancer::reallyOpenConnection
  0.07% 3.939    712 - Cdb\Reader\PHP::readInt32
  0.07% 3.928    708 - Language::uc
  0.07% 3.923      1 - Skin::printSource
  0.07% 3.912      2 - Message::__toString
  0.07% 3.803      2 - MediaWiki\Storage\RevisionStore::fetchRevisionRowFromConds
  0.07% 3.801    110 - fwrite
  0.07% 3.792      2 - Wikimedia\Rdbms\Database::factory
  0.07% 3.787      1 - Parser::firstCallInit
  0.07% 3.749      1 - ExtensionRegistry::loadFromQueue
  0.07% 3.728      1 - GadgetHooks::userGetDefaultOptions
  0.07% 3.698     16 - MediaWiki\Services\ServiceContainer::{closure}
  0.07% 3.694      5 - MediaWikiGadgetsDefinitionRepo::getGadgetIds
  0.07% 3.681      1 - GadgetRepo::getStructuredList
  0.07% 3.678      5 - MediaWikiGadgetsDefinitionRepo::loadGadgets
  0.07% 3.639      9 - WikiPage::exists
  0.07% 3.632      1 - WikiPage::loadPageData
  0.06% 3.607      1 - ResourceLoaderClientHtml::getData
  0.06% 3.558      2 - Wikimedia\Rdbms\Database::initConnection
  0.06% 3.533      2 - Wikimedia\Rdbms\Database::doInitConnection
  0.06% 3.523      2 - Wikimedia\Rdbms\DatabaseMysqlBase::open
  0.06% 3.502      1 - Block::newLoad
  0.06% 3.488      1 - User::loadFromDatabase
  0.06% 3.481      1 - Wikibase\Repo\WikibaseRepo::getEntityRevisionLookup
  0.06% 3.481      3 - Skin::footerLink
  0.06% 3.428   1889 - Monolog\Formatter\NormalizerFormatter::normalize@2
  0.06% 3.248    900 - Cdb\Reader\PHP::read
  0.06% 3.234     68 - User::loadGroups
  0.06% 3.230      1 - MediaWikiGadgetsDefinitionRepo::{closure}
  0.06% 3.178      1 - ResourceLoaderContext::newDummyContext
  0.06% 3.139      1 - UserGroupMembership::getMembershipsForUser
  0.06% 3.129      4 - Parser::formatHeadings
  0.06% 3.124      1 - MediaWikiGadgetsDefinitionRepo::fetchStructuredList
  0.06% 3.114      1 - VectorTemplate::renderPortals
  0.06% 3.077     55 - wfTimestamp
  0.06% 3.063      2 - VectorTemplate::renderPortal
  0.06% 3.062      1 - Skin::getNewtalks
  0.05% 3.058      1 - Revision::newFromTitle
  0.05% 3.034     59 - Wikimedia\Timestamp\ConvertibleTimestamp::convert
  0.05% 2.999      2 - User::getNewMessageLinks
  0.05% 2.991      1 - Skin::buildSidebar
  0.05% 2.984      3 - User::getNewtalk
  0.05% 2.970      1 - Skin::{closure}
  0.05% 2.970    263 - Monolog\Formatter\NormalizerFormatter::toJson
  0.05% 2.969      1 - User::checkNewtalk
  0.05% 2.957      1 - Skin::addToSidebar
  0.05% 2.908     93 - Parser::setFunctionHook
  0.05% 2.895     22 - MediaWiki\Services\ServiceContainer::getService@2
  0.05% 2.883      5 - Wikibase\DataAccess\MultipleRepositoryAwareWikibaseServices::Wikibase\DataAccess\{closure}
  0.05% 2.858     12 - MediaWiki\Services\ServiceContainer::createService@2
  0.05% 2.851    576 - Monolog\Formatter\LineFormatter::convertToString
  0.05% 2.832     40 - Wikimedia\Rdbms\Database::tableNamesWithIndexClauseOrJOIN
  0.05% 2.830     25 - Language::getMessageFromDB
  0.05% 2.826      1 - Skin::addToSidebarPlain
  0.05% 2.814      4 - Wikibase\Repo\WikibaseRepo::{closure}
  0.05% 2.738     96 - MediaWiki\Logger\Monolog\LegacyHandler::write
  0.05% 2.733     10 - Title::quickUserCan
  0.05% 2.720      1 - Wikibase\SqlStore::getEntityRevisionLookup
  0.05% 2.714      1 - Wikibase\SqlStore::newEntityRevisionLookup
  0.05% 2.650      1 - Skin::lastModified
  0.05% 2.615      6 - Skin::footerLinkTitle
  0.05% 2.562      2 - Wikibase\DataAccess\MultiRepositoryServices::getServiceMap
  0.05% 2.522    263 - Monolog\Formatter\NormalizerFormatter::jsonEncode
  0.05% 2.516     49 - Title::getLocalURL
  0.05% 2.505      1 - MediaWiki\Storage\RevisionStore::getRevisionByTitle
  0.04% 2.504      1 - Wikibase\DataAccess\MultipleRepositoryAwareWikibaseServices::getEntityRevisionLookup
  0.04% 2.489      1 - Wikibase\DataAccess\MultiRepositoryServices::getEntityRevisionLookup
  0.04% 2.472      1 - MWEchoNotifUser::getAlertCount
  0.04% 2.450     76 - Linker::accesskey
  0.04% 2.445      1 - MediaWiki\Storage\RevisionStore::loadRevisionFromConds
  0.04% 2.416      2 - MWEchoNotifUser::getLastUnreadNotificationTime
  0.04% 2.380      1 - WikiPage::loadFromRow
  0.04% 2.379    561 - Cdb\Reader\PHP::readInt31
  0.04% 2.369      1 - LinkBatch::doQuery
  0.04% 2.361     16 - LocalisationCache::loadItem
  0.04% 2.321     61 - Wikimedia\Timestamp\ConvertibleTimestamp::__construct
  0.04% 2.265    121 - Html::rawElement
  0.04% 2.263      8 - User::getEffectiveGroups
  0.04% 2.250      5 - ResourceLoaderWikiModule::isKnownEmpty
  0.04% 2.238     57 - Wikimedia\Rdbms\Database::tableNameWithAlias
  0.04% 2.229      2 - EchoNotificationController::formatNotificationCount
  0.04% 2.223      1 - ParserCache::getKey
  0.04% 2.218    277 - json_encode
  0.04% 2.218      5 - ResourceLoaderWikiModule::getTitleInfo
  0.04% 2.212    575 - GlobalVarConfig::get
  0.04% 2.210     61 - Wikimedia\Timestamp\ConvertibleTimestamp::setTimestamp
  0.04% 2.204     12 - Title::checkCascadingSourcesRestrictions
  0.04% 2.196      3 - User::getAutomaticGroups
  0.04% 2.189      1 - Title::getCascadeProtectionSources
  0.04% 2.145    183 - LocalisationCache::getItem
  0.04% 2.129    129 - Html::openElement
  0.04% 2.111      3 - Autopromote::getAutopromoteGroups
  0.04% 2.073     62 - Wikimedia\Rdbms\Database::makeList
  0.04% 2.027    112 - Composer\Autoload\ClassLoader::loadClass
  0.04% 2.008      4 - MemcachedClient::_set
  0.04% 2.007   1868 - ResourceLoader::isFileModule
  0.04% 1.998      1 - section.Setup.php-extensions
  0.04% 1.984    800 - preg_match
  0.04% 1.984      1 - Title::loadRestrictions
  0.04% 1.984      3 - Linker::linkKnown
  0.04% 1.979      3 - Linker::link
  0.04% 1.974      8 - ResourceLoaderClientHtml::makeLoad
  0.04% 1.974     11 - Title::checkQuickPermissions
  0.04% 1.973      2 - Wikibase\Repo\WikibaseRepo::{closure}@1
  0.04% 1.968     27 - User::isAllowed
  0.04% 1.949      7 - WikiPage::getRevision
  0.03% 1.937      7 - WikiPage::loadLastEdit
  0.03% 1.911    900 - Language::isMultibyte
  0.03% 1.900      4 - Title::getRestrictionTypes
  0.03% 1.898      1 - Revision::newKnownCurrent
  0.03% 1.897    106 - spl_autoload_call@1
  0.03% 1.878      1 - MediaWiki\Storage\RevisionStore::getKnownCurrentRevision
  0.03% 1.862      2 - EchoNotificationMapper::fetchUnreadByUser
  0.03% 1.856      2 - EchoNotificationMapper::fetchByUserInternal
  0.03% 1.841     27 - User::getRights
  0.03% 1.831      1 - DroidWikiHooks::onSkinTemplateOutputPageBeforeExec
  0.03% 1.803     20 - Wikibase\SettingsArray::getSetting
  0.03% 1.798      1 - SkinTemplate::buildNavUrls
  0.03% 1.785    108 - Wikimedia\Rdbms\ResultWrapper::next
  0.03% 1.784     55 - Wikimedia\Rdbms\Database::tableName
  0.03% 1.771      3 - ResourceLoaderClientHtml::getLoad
  0.03% 1.739      3 - MediaWiki\Linker\LinkRenderer::makeKnownLink
  0.03% 1.738      2 - MessageCache::saveToCaches
  0.03% 1.724      1 - CoreParserFunctions::register
  0.03% 1.721      1 - Block::__construct
  0.03% 1.707     14 - MemcachedClient::_fwrite
  0.03% 1.687      5 - SqlBagOStuff::getDB
  0.03% 1.628      3 - MediaWiki\Linker\LinkRenderer::makePreloadedLink
  0.03% 1.626    108 - Wikimedia\Rdbms\ResultWrapper::fetchObject
  0.03% 1.613      1 - ExtensionRegistry::exportExtractedData
  0.03% 1.607    111 - Cdb\Util::hash
  0.03% 1.588      8 - MediaWiki\Services\ServiceContainer::{closure}@1
  0.03% 1.584    217 - fread
  0.03% 1.577      1 - Skin::aboutLink
  0.03% 1.576     26 - Preprocessor_DOM::preprocessToXml
  0.03% 1.567      1 - OutputPage::getHeadLinksArray
  0.03% 1.546     13 - Language::getMonthName
  0.03% 1.541      2 - Wikimedia\Rdbms\DatabaseMysqli::mysqlConnect
  0.03% 1.539    115 - Wikimedia\Rdbms\DatabaseMysqlBase::fetchObject
  0.03% 1.535      6 - User::newFromName
  0.03% 1.518      2 - MemcachedBagOStuff::set
  0.03% 1.514      1 - LinkBatch::doGenderQuery
  0.03% 1.507    129 - Html::expandAttributes
  0.03% 1.495      2 - MemcachedClient::set
  0.03% 1.488      9 - APCBagOStuff::doGet
  0.03% 1.487      6 - User::getCanonicalName
  0.03% 1.487     22 - Parser::startParse
  0.03% 1.481      1 - GenderCache::doLinkBatch
  0.03% 1.465      1 - MWEchoNotifUser::getGlobalUpdateTime
  0.03% 1.463      1 - GenderCache::doQuery
  0.03% 1.461      2 - MediaWiki\Storage\RevisionStore::MediaWiki\Storage\{closure}
  0.03% 1.449      1 - Skin::disclaimerLink
  0.03% 1.447      1 - Language::getMonthNamesArray
  0.03% 1.442      9 - apc_fetch
  0.03% 1.441   1868 - ResourceLoader::isValidModuleName
  0.03% 1.440    971 - Hooks::getHandlers
  0.03% 1.440      1 - Wikibase\Repo\Hooks\OutputPageJsConfigHookHandler::onOutputPageBeforeHtmlRegisterConfig
  0.03% 1.439      3 - AbuseFilterHooks::onGetAutoPromoteGroups
  0.03% 1.424     58 - mb_strtoupper
  0.03% 1.424    611 - is_callable
  0.03% 1.422      2 - Skin::makeInternalOrExternalUrl
  0.03% 1.419    101 - User::getOption
  0.03% 1.412      1 - Wikibase\Repo\Hooks\OutputPageJsConfigHookHandler::newFromGlobalState
  0.03% 1.409      1 - Skin::makeUrl
  0.02% 1.388      1 - Article::adjustDisplayTitle
  0.02% 1.368    240 - wfMessage
  0.02% 1.365    221 - MagicWord::get
  0.02% 1.360     56 - MediaWiki\Logger\LoggerFactory::getInstance
  0.02% 1.359   2061 - str_replace
  0.02% 1.358      1 - EmbedVideoHooks::onParserFirstCallInit
  0.02% 1.347    130 - Wikimedia\Rdbms\DatabaseMysqlBase::addQuotes
  0.02% 1.341      1 - MWEchoNotifUser::getLastUnreadMessageTime
  0.02% 1.338    100 - Composer\Autoload\includeFile
  0.02% 1.336     22 - Parser::clearState
  0.02% 1.329      1 - Language::getMonthAbbreviationsArray
  0.02% 1.315     12 - Language::getMonthAbbreviation
  0.02% 1.315      1 - ResourceLoader::makeModuleResponse
  0.02% 1.303     56 - MediaWiki\MediaWikiServices::getDBLoadBalancer
  0.02% 1.296    357 - Wikimedia\Assert\Assert::parameterType
  0.02% 1.292    576 - GlobalVarConfig::has
  0.02% 1.282    159 - DateTime::__construct
  0.02% 1.279      3 - ResourceLoaderUserStylesModule::getPages
  0.02% 1.273    901 - mb_strlen
  0.02% 1.273      6 - Wikibase\Repo\WikibaseRepo::{closure}@2
  0.02% 1.269      4 - BagOStuff::getWithSetCallback
  0.02% 1.269     50 - MediaWiki\Interwiki\ClassicInterwikiLookup::fetch
  0.02% 1.250    576 - Wikimedia\Assert\Assert::hasType
  0.02% 1.247     91 - Title::getPrefixedDBkey
  0.02% 1.237      1 - MediaWiki\Interwiki\ClassicInterwikiLookup::isValidInterwiki
  0.02% 1.233      1 - section.Setup.php-memcached
  0.02% 1.217      1 - MediaWiki\Interwiki\ClassicInterwikiLookup::load
  0.02% 1.212      3 - MediaWiki\Linker\LinkRenderer::runBeginHook
  0.02% 1.203     26 - DOMDocument::loadXML
  0.02% 1.203    105 - Title::prefix
  0.02% 1.201      1 - AbuseFilterHooks::{closure}
  0.02% 1.198      1 - BaseTemplate::makeSearchInput
  0.02% 1.198      1 - WikiPage::pageDataFromTitle
  0.02% 1.193     30 - Revision::getRevisionText
  0.02% 1.193      3 - MediaWiki\Linker\LinkRenderer::runLegacyBeginHook
  0.02% 1.191      1 - WikiPage::pageData
  0.02% 1.186      2 - MwEmbedResourceManager::registerModules
  0.02% 1.181     89 - AutoLoader::autoload@1
  0.02% 1.166    136 - User::getId
  0.02% 1.164     71 - MediaWiki\Logger\Monolog\LogstashFormatter::formatV1
  0.02% 1.164     75 - User::isLoggedIn
  0.02% 1.150    510 - Wikimedia\suppressWarnings
  0.02% 1.149    593 - preg_replace
  0.02% 1.147     65 - ContextSource::msg
  0.02% 1.147     13 - MediaWiki\Services\ServiceContainer::applyWiring
  0.02% 1.142     38 - ResourceLoaderClientHtml::makeContext
  0.02% 1.139      2 - Wikimedia\Rdbms\DatabaseMysqli::selectDB
  0.02% 1.134     54 - User::isAnon
  0.02% 1.118      2 - mysqli::select_db
  0.02% 1.107    203 - is_subclass_of
  0.02% 1.104      5 - Language::factory
  0.02% 1.099     10 - Parser::callParserFunction
  0.02% 1.093      2 - MediaWiki\MediaWikiServices::newInstance
  0.02% 1.091    130 - Wikimedia\Rdbms\Database::addQuotes
  0.02% 1.086      2 - mysqli::real_connect
  0.02% 1.082      1 - MWEchoNotifUser::getLastUnreadAlertTime
  0.02% 1.080     56 - MediaWiki\Logger\MonologSpi::getLogger
  0.02% 1.076      3 - Wikibase\Repo\Hooks\LinkBeginHookHandler::onLinkBegin
  0.02% 1.074      1 - MediaWiki\Interwiki\ClassicInterwikiLookup::MediaWiki\Interwiki\{closure}
  0.02% 1.071      2 - Language::newFromCode
  0.02% 1.070      1 - Title::loadRestrictionsFromRows
  0.02% 1.070      3 - Block::parseTarget
  0.02% 1.065     48 - call_user_func@1
  0.02% 1.059      3 - ResourceLoaderModule::getModuleContent
  0.02% 1.049      2 - Block::setTarget
  0.02% 1.046      8 - Title::newMainPage
  0.02% 1.038     16 - Wikimedia\ObjectFactory::getObjectFromSpec
  0.02% 1.037     14 - Message::escaped
  0.02% 1.029     11 - Parser::getVariableValue
  0.02% 1.028     14 - MemcachedClient::get_sock
  0.02% 1.020      4 - EchoAttributeManager::getUserEnabledEventsbySections
  0.02% 1.009     34 - ResourceLoaderClientHtml::getContext
  0.02% 1.005     70 - MediaWikiTitleCodec::getNamespaceName

Interestingly, the second one waits until the database replica has a specific position, however, the replica seems to catch up nearly immediately after writing to the master, which doesn't seem to match with the profiling result :/

FlorianSW commented 6 years ago

For documentation, the log warning issued by ChronologyPager every time:

{
  "_index": "logstash-2018.05.26",
  "_type": "mediawiki",
  "_id": "AWOcDYJMscN410QcnHiP",
  "_version": 1,
  "_score": null,
  "_source": {
    "server": "www.droidwiki.org",
    "process_id": 7567,
    "level": "WARNING",
    "ip": "<stripped>",
    "wiki": "droidwikiwiki",
    "channel": "DBReplication",
    "mwversion": "1.32.0-wmf.5",
    "message": "Wikimedia\\Rdbms\\ChronologyProtector::initPositions: expected but failed to find position index.",
    "type": "mediawiki",
    "url": "/wiki/HTC/Tattoo",
    "reqId": "c83dd1fc585922b766e33ae0",
    "tags": [
      "redis",
      "es",
      "_grokparsefailure",
      "_geoip_lookup_failure"
    ],
    "referrer": "<stripped>",
    "uid": "<stripped>",
    "@timestamp": "2018-05-26T10:45:21.001Z",
    "http_method": "GET",
    "cpPosIndex": 1,
    "@version": 1,
    "host": "v22015052656325188",
    "waitTimeMs": 5288.453817367554,
    "indexReached": null
  },
  "fields": {
    "@timestamp": [
      1527331521001
    ]
  },
  "highlight": {
    "message": [
      "Wikimedia\\Rdbms\\ChronologyProtector::@kibana-highlighted-field@initPositions@/kibana-highlighted-field@: @kibana-highlighted-field@expected@/kibana-highlighted-field@ but failed to find position index."
    ]
  },
  "sort": [
    1527331521001
  ]
}