We are having this Dbperformance spam
2015-08-30 16:21:24 mw1 metawiki: [GET] Expectation (writes <= 0) by MediaWiki::main not met:
query: UPDATE user SET user_name = 'X' [TRX#2d661da95b5d]
TransactionProfiler.php line 271 calls wfBacktrace()
TransactionProfiler.php line 181 calls TransactionProfiler->reportExpectationViolated()
Database.php line 1165 calls TransactionProfiler->recordQueryCompletion()
Database.php line 2153 calls DatabaseBase->query()
User.php line 3631 calls DatabaseBase->update()
UniversalLanguageSelector.hooks.php line 211 calls User->saveSettings()
Hooks.php line 209 calls UniversalLanguageSelectorHooks::getLanguage()
RequestContext.php line 346 calls Hooks::run()
Message.php line 577 calls RequestContext->getLanguage()
RequestContext.php line 436 calls Message->setContext()
SpecialPage.php line 608 calls RequestContext->msg()
SpecialPage.php line 466 calls SpecialPage->msg()
SpecialPage.php line 355 calls SpecialPage->getDescription()
SpecialCreateWiki.php line 10 calls SpecialPage->setHeaders()
SpecialPage.php line 384 calls SpecialCreateWiki->execute()
SpecialPageFactory.php line 582 calls SpecialPage->run()
MediaWiki.php line 267 calls SpecialPageFactory::executePath()
MediaWiki.php line 566 calls MediaWiki->performRequest()
MediaWiki.php line 414 calls MediaWiki->main()
index.php line 41 calls MediaWiki->run()
Description
Event Timeline
Hi @Reception123, thanks for taking the time to report this!
Unfortunately this report lacks some information. If you have time and can still reproduce the problem, please add a more useful and complete description to this report. Steps to reproduce should allow another person to follow those steps (leaving no room for interpretation) and see the same results, e.g. version information, where the pasted content comes from, what "DBperformance" is and why this was filled only four months (2015-08-30) after it happened? :)
This is in response to this GH issue, which we tried to handle internally; or something.
The issue says this is in dbperformance.log, but atm I'm not sure if that's custom logging we do, or if it's part of MediaWiki and/or our SQL servers.
As always, our live mediawiki versions and configurations are available on our GitHub. I'll try to update this if I find more relevant information.
Cheers, NDKilla (Miraheze mediawiki-admin (mediawiki server shell) and Steward)
I have seen similar output log spamming starting with 1.26 with message that were previously irrelevant.
[DBPerformance] [GET] Expectation (writes <= 0) by MediaWiki::main not met: means exactly what? Having an extension to write the DB in an isolate transaction should not fill the log file with spam.
Article::view using parser cache: yes
Parser options key expired, touched 20151228032608, epoch 20151227231618, cached 20151227214745
Article::view: doing uncached parse
Parser cache options found.
DatabaseBase::query: Writes done: DELETE FROM `smw_query_links` WHERE s_id = 'X'
[DBPerformance] [GET] Expectation (writes <= 0) by MediaWiki::main not met:
query: DELETE FROM `smw_query_links` WHERE s_id = 'X' [TRX#3784241c5941]
TransactionProfiler.php line 307 calls wfBacktrace()
TransactionProfiler.php line 200 calls TransactionProfiler->reportExpectationViolated()
Database.php line 1035 calls TransactionProfiler->recordQueryCompletion()
Database.php line 2977 calls DatabaseBase->query()
Database.php line 343 calls DatabaseBase->delete()
EmbeddedQueryDependencyLinksStore.php line 287 calls SMW\MediaWiki\Database->delete()
EmbeddedQueryDependencyLinksStore.php line 247 calls SMW\SQLStore\EmbeddedQueryDependencyLinksStore->updateDependencyList()
HookRegistry.php line 553 calls SMW\SQLStore\EmbeddedQueryDependencyLinksStore->addDependencyList()
- line - calls SMW\MediaWiki\Hooks\HookRegistry->SMW\MediaWiki\Hooks\{closure}()
Hooks.php line 204 calls call_user_func_array()
GlobalFunctions.php line 4022 calls Hooks::run()
SMW_SQLStore3.php line 374 calls wfRunHooks()
SMW_QueryProcessor.php line 510 calls SMWSQLStore3->getQueryResult()
AskParserFunction.php line 176 calls SMWQueryProcessor::getResultFromQuery()
AskParserFunction.php line 133 calls SMW\AskParserFunction->doFetchResultsForRawParameters()
ParserFunctionFactory.php line 252 calls SMW\AskParserFunction->parse()
- line - calls SMW\ParserFunctionFactory->SMW\{closure}()
Parser.php line 3789 calls call_user_func_array()
Parser.php line 3523 calls Parser->callParserFunction()
Preprocessor_DOM.php line 1177 calls Parser->braceSubstitution()
Parser.php line 3342 calls PPFrame_DOM->expand()
Parser.php line 1239 calls Parser->replaceVariables()
Parser.php line 439 calls Parser->internalParse()
WikitextContent.php line 331 calls Parser->parse()
AbstractContent.php line 497 calls WikitextContent->fillParserOutput()
PoolWorkArticleView.php line 140 calls AbstractContent->getParserOutput()
PoolCounterWork.php line 123 calls PoolWorkArticleView->doWork()
Article.php line 676 calls PoolCounterWork->execute()
ViewAction.php line 44 calls Article->view()
MediaWiki.php line 458 calls ViewAction->show()
MediaWiki.php line 255 calls MediaWiki->performAction()
MediaWiki.php line 682 calls MediaWiki->performRequest()
MediaWiki.php line 476 calls MediaWiki->main()
index.php line 41 calls MediaWiki->run()
Saved in parser cache with key mw-26-00:pcache:idhash:6-0!*!0!*!*!*!* and timestamp 20151228033135 and revision id 6