Page MenuHomePhabricator

Uncommitted DB writes (transaction from DatabaseBase::query (Block::newLoad))
Closed, ResolvedPublicPRODUCTION ERROR

Description

Notice: Uncommitted DB writes (transaction from DatabaseBase::query (Block::newLoad)). in /usr/local/apache/common-local/php-1.23wmf1/includes/db/Database.php on line 3904

Seems to be new in 1.23wmf1, should probably be looked into


Version: unspecified
Severity: major
See Also:
https://bugzilla.wikimedia.org/show_bug.cgi?id=47375

Details

Reference
bz56269

Event Timeline

There are a very large number of changes, so older changes are hidden. Show Older Changes

I've seen it on MessageBlobStore::clear() once on my wiki.

Notice: Uncommitted DB writes (transaction from DatabaseBase::query (WikiPage::pageData)). in /usr/local/apache/common-local/php-1.23wmf1/includes/db/Database.php on line 3904

After some tests on a fresh wiki install, severity bumped to major, as some important functionnalities are broken: the error is also triggered after settings update (User::saveSettings) or when saving MediaWiki: messages (already hinted in previous comments). As read-only use and most edit uses still work, this is not a blocker.

I'm getting this on master when trying to view the main page of my wiki.

Notice: Uncommitted DB writes (transaction from DatabaseBase::query (MessageBlobStore::clear)). in /home/WWW/matmarex/WWW/testwiki/includes/db/Database.php on line 3904

Running update.php fixed it for me. This might not be a real issue after all, just a very misleading error message.

(The commit with schema changes is I54124664, which would also mean this is just master, not 1.22.)

CC'ing translatewiki folks:

Siebrand/Niklas: Are you seeing this issue on translatewiki? I hear it tends to hit these issues? We're looking for help reproducing.

Seeing these regularly on twn, and AFAIK we have no idea weer they come from.

Siebrand, is TWN's database updated with the schema change from I54124664?

I've recently seen these on twn (unique occurrences):

[06-Nov-2013 03:45:38 UTC] PHP Notice: Uncommitted DB writes (transaction from DatabaseBase::query (MessageGroupStats::selectRowsIdLang)). in /www/translatewiki.net/w/includes/db/Database.php on line 3988
[06-Nov-2013 09:56:22 UTC] PHP Notice: Uncommitted DB writes (transaction from DatabaseBase::query (WikiPage::pageData)). in /www/translatewiki.net/w/includes/db/Database.php on line 3988
[06-Nov-2013 15:31:24 UTC] PHP Notice: Uncommitted DB writes (transaction from DatabaseBase::query (User::loadFromDatabase)). in /www/translatewiki.net/w/includes/db/Database.php on line 3988
[06-Nov-2013 20:39:29 UTC] PHP Notice: Uncommitted DB writes (transaction from DatabaseBase::query (ResourceLoader::preloadModuleInfo)). in /www/translatewiki.net/w/includes/db/Database.php on line 3988

I've found one way to reproduce this issue: if something causes a transaction start (likely via DBO_TRX or DBO_DEFAULT) and then something throws an exception that makes its way into MWExceptionHandler::handle, the database connection isn't properly shut down before exit() is called. Since gerrit change 79852, this causes log messages about uncommitted DB writes when the database object is destroyed.

(In reply to comment #13)

I've found one way to reproduce this issue: if something causes a transaction
start (likely via DBO_TRX or DBO_DEFAULT) and then something throws an
exception that makes its way into MWExceptionHandler::handle, the database
connection isn't properly shut down before exit() is called. Since Gerrit
change #79852, this causes log messages about uncommitted DB writes when the
database object is destroyed.

Of course this is a symptom rather than a cause.

And it being a recent change means it's more visible, rather than potentially failing silently in the background

Same?

<b>Notice</b>: Uncommitted DB writes (transaction from DatabaseBase::query (LinkBatch::doQuery (for Skin::preloadExistence))). in <b>/www/dev.translatewiki.net/w/includes/db/Database.php</b> on line <b>4118</b>
http://dev.translatewiki.net/wiki/Special:ChangePassword (logged out, but not logged in)

Just did a fresh install using 1.22.0rc3. No extensions installed at this point.

  • Language: English
  • Environmental checks, got warnings:
    • Could not find APC, XCache, or WinCache
    • The intl PECL extension is not available to handle Unicode normalization, falling back on slow pure-PHP implementation
  • Otherwise all env checks were good
  • Database: MySQL on localhost, no db table prefix, InnoDB, Binary
  • Private wiki
  • No license footer
  • Disable outbound email (for now)
  • Enable uploads, keeping defaults for deleted files and log URL
  • No caching

Prior to login I see:
Notice: Uncommitted DB writes (transaction from DatabaseBase::query (MessageBlobStore::clear)). in C:\xampp\htdocs\wiki\mod\includes\db\Database.php on line 3944

I login and the error went away.

MediaWiki 1.22.0rc3 (0e84337)
PHP 5.4.7 (apache2handler)
MySQL 5.5.27
Windows 7

Maybe relevant? From #mediawiki:

<songoo> MatmaRex : first i tried to add "$wgGroupPermissions['sysop']['userrights'] = true;" at end of LocalSettings.php, nothing changed, then i noticed "user_groups" table is empty (fresh mediawiki install from git) , so i tied "INSERT INTO user_groups (ug_user, ug_group) VALUES (1, 'sysop');" , have just one defult admnin user with ID 1 . And it worked, "Uncommitted DB writes" notice is gone, and also finnaly i can edit user right

(In reply to comment #9)

Seeing these regularly on twn, and AFAIK we have no idea weer they come from.

FWIW, about 400 a month, or 20 % of rakkaus output.

  • Bug 60047 has been marked as a duplicate of this bug. ***

christopher.dieringer wrote:

Ditto. Fresh 1.22.1 installation, setup for private. Minimal extensions. Able to access the home page, but cannot enter the login page without server timeout.

Suggestion for someone familiar with Git (I'm not) who is experiencing the problem: you might be able to isolate the change between 1.21 and 1.22 that caused the problem by binary search:

  1. Check out v 1.21 and confirm the problem is absent
  2. Check out the version halfway between 1.21 and 1.22 and look for the problem. If present, check out the version halfway between 1.21 and it. If absent, check out the version halfway between 1.22 and it.
  3. Continue cutting the space in half until you have 2 adjacent versions, the lower one missing the problem, and the higher one containing the problem. Report that higher version here.

I've done this before to isolate MediaWiki bugs. It takes less time than one might think.

  • Bug 60553 has been marked as a duplicate of this bug. ***

I've seen this error, too, and now someone reported it on the Support Desk ( [[Thread:Project:Support desk/Uncommitted DB writes - DB error]]).

This should be fixed in the next point release of MediaWiki. Now, to find someone to fix it.

zacharyharris wrote:

I get this when I'm logged in and click on "preferences".

Using 1.23alpha, updated as of this post time.

Same problem, error message as notice when call User::saveSettings() from external PHP file to save a new Option (setOption()). Maybe it's related to this bug, here more information:
http://stackoverflow.com/questions/22260275/mediawiki-setoption-on-own-php-page

MW 1.23wmf11
PHP 5.3.3-7+squeeze19
MySQL 5.1.73-1-log

Recently it starts showing up for Title::getCascadeProtectionSources on twn:

PHP Notice: Uncommitted DB writes (transaction from DatabaseBase::query (Title::getCascadeProtectionSources)). in /www/translatewiki.net/w/includes/db/Database.php on line 4132

Recommending this block the 1.23.0 release. It surfaces as "only" a PHP Notice, but uncommitted db writes seem quite like a sign of bad quality code that is sufficiently low level that it could all kinds of unforeseen side effects and might leave the database in a state from which we have no way to recover from.

(In reply to Krinkle from comment #28)

Recommending this block the 1.23.0 release.

Agreed.

Change 121402 had a related patch set uploaded by Anomie:
Improve handling of uncommitted DB txns with "uncaught" exceptions

https://gerrit.wikimedia.org/r/121402

Applied patch to all files, but in my example use of mediawiki's functions (https://bugzilla.wikimedia.org/show_bug.cgi?id=56269#c26) the patch doesn't fix the problem, same error message:
Notice: Uncommitted DB writes (transaction from DatabaseBase::query (LCStoreDB::get)). in /var/www/wiki/includes/db/Database.php on line 4147 Notice: DB transaction callbacks still pending (from User::invalidateCache, Title::invalidateCache). in /var/www/wiki/includes/db/Database.php on line 4155

(In reply to florian.schmidt.welzow from comment #31)

Applied patch to all files, but in my example use of mediawiki's functions
(https://bugzilla.wikimedia.org/show_bug.cgi?id=56269#c26) the patch doesn't
fix the problem

This bug is about the error message showing up from MediaWiki itself. Your issue there is that you're not shutting down the database connections at all; it's probably best to continue discussion of your code on Stack Overflow.

steven wrote:

MW 1.22.5, new and clean install:

Notice: Uncommitted DB writes (transaction from DatabaseBase::query (MessageBlobStore::clear)). in C:\xampp\htdocs\new\includes\db\Database.php on line 3944

https://bugzilla.wikimedia.org/show_bug.cgi?id=63213

  • Bug 63213 has been marked as a duplicate of this bug. ***

Change 121402 merged by jenkins-bot:
Improve handling of uncommitted DB txns with "uncaught" exceptions

https://gerrit.wikimedia.org/r/121402

Change 127868 had a related patch set uploaded by Aaron Schulz:
Avoid uncommitted transaction notices in thumb.php and img_auth.php

https://gerrit.wikimedia.org/r/127868

Change 127868 merged by jenkins-bot:
Avoid uncommitted transaction notices in thumb.php and img_auth.php

https://gerrit.wikimedia.org/r/127868

  • Bug 64481 has been marked as a duplicate of this bug. ***

(In reply to Mark A. Hershberger from comment #29)

(In reply to Krinkle from comment #28)

Recommending this block the 1.23.0 release.

Agreed.

Raising to "Highest" as we were told to do for 1.23.

Since 2014-04-16, the number of such errors on translatewiki.net has decreased to less than ten per day, for the first time since 2014-02-28. It's not clear to me what's the correlation to merged patches though.

And now it disappeared on translatewiki.net, for equally unknown reasons. The last was:

2014-04-25 19.00 -rakkaus:#mediawiki-i18n- [25-Apr-2014 16:59:57 UTC] PHP Notice: Uncommitted DB writes (transaction from DatabaseBase::query (ResourceLoader::preloadModuleInfo)). in /www/translatewiki.net/w/includes/db/Database.php on line 4149

(In reply to Nemo from comment #40 on 2014-05-05)

And now it disappeared on translatewiki.net

The last of the four patches mentioned here was merged on 2014-04-22.

Resetting bug status to NEW, though it's unclear to me if there's more work needed or if this can be closed as FIXED now.

(In reply to Krinkle from comment #28)

Recommending this block the 1.23.0 release.

I assume that some of the patches should be considered for backporting from git master to the REL1_23 branch?
Could somebody provide input / a recommendation for Mark and Markus?

(In reply to Andre Klapper from comment #41)

(In reply to Nemo from comment #40 on 2014-05-05)

And now it disappeared on translatewiki.net

The last of the four patches mentioned here was merged on 2014-04-22.

Resetting bug status to NEW, though it's unclear to me if there's more work
needed or if this can be closed as FIXED now.

I talked to Niklas and he showed me instances of this happening today on twn.

So it isn't fixed completely and there is still more work needed.

(In reply to Krinkle from comment #28)

Recommending this block the 1.23.0 release.

I assume that some of the patches should be considered for backporting from
git master to the REL1_23 branch?
Could somebody provide input / a recommendation for Mark and Markus?

I'll try to find out from Niklas if the instance of this has at least been reduced.

It seems reduced. Output sorted manually to date order. Please note the days which have no occurrences at all.

grep 'Uncommitted DB' error* -h | cut -f 1 -d " " | sed 's/\[//g'| uniq -c

24 06-Apr-2014
39 07-Apr-2014
29 08-Apr-2014
32 09-Apr-2014
53 10-Apr-2014
28 11-Apr-2014
38 12-Apr-2014
 9 13-Apr-2014
12 14-Apr-2014
24 15-Apr-2014
 4 16-Apr-2014
 3 17-Apr-2014
 1 19-Apr-2014
 2 20-Apr-2014
 3 21-Apr-2014
 1 23-Apr-2014
 2 24-Apr-2014
 1 25-Apr-2014
 7 06-May-2014
 3 07-May-2014
 1 08-May-2014
 2 09-May-2014

I think adding the following sort would work:

... | sed 's/\[//g'| uniq -c | sort -k 2

This is encouraging. Leaving bug open but moving milestone.

If someone has a quick fix and can apply it in the next week, that would still be awesome. Still, I'm happy with what is seen here.

mg169706 wrote:

I have been trying to install MW 1.23 RC1 and I'm getting this error. The error occurs when the installer startes the database upgrade process. Replicated below for clarity:

Notice: Uncommitted DB writes (transaction from DatabaseUpdater::doUpdates). in C:\LG_WIKI_1-23\includes\db\Database.php on line 4147

I have checked the patches in the comments further up the page and they're all applied to my installation.

Somewhere, I think it was on this page, I saw someone suggested running update.php. I tried this and received a database error. I have copied the error below, including the last few lines of update.php's output. Assuming that the upgrade process in the installer runs this script, could this error be somehow causing teh first error message above?

Ben

Last few lines of output from update.php:

...up_property in table user_properties already modified by patch patch-up_property.sql.
...uploadstash table already exists.
...user_former_groups table already exists.
...index type_action already set on logging table.
...have rev_sha1 field in revision table.
...batch conversion of user_options: A database query error has occurred.
Query: UPDATE ew_user SET user_name = 'BColeman',user_password = ':B:65b95335:fefb11de795fc238ad1ebd86db5d24b3',user_newpassword = '',user_newpass_time = NULL,user_real_name = 'Brendan Coleman',user_email = 'Brendan.Coleman@airbus.com',user_email_authenticated = NULL,user_touched = '20140521112253',user_token = '043afef4dd0d8dc602549dbcdf04aa79',user_email_token = '',user_email_token_expires = NULL,user_password_expires = NULL WHERE user_id = '90'
Function: User::saveSettings
Error: 1054 Unknown column 'user_password_expires' in 'field list' (localhost)

mg169706 wrote:

I managed to remove the above error by manually adding the column "user_password_expires" to the user table. I don't know enough about the structure of the MW code to check to see if update.php is checking/creating this column before trying to use it.

For reference, I'm updating from MW 1.18.6 which lacks this column.

Ben

(In reply to ben from comment #46)

I managed to remove the above error by manually adding the column
"user_password_expires" to the user table. I don't know enough about the
structure of the MW code to check to see if update.php is checking/creating
this column before trying to use it.

It should but it doesn't, that's a separate bug that should be fixed before 1.23 release: bug 63677.

(In reply to Nemo from comment #40)

And now it disappeared on translatewiki.net, for equally unknown reasons.
The last was:

2014-04-25 19.00 -rakkaus:#mediawiki-i18n- [25-Apr-2014 16:59:57 UTC] PHP
Notice: Uncommitted DB writes (transaction from DatabaseBase::query
(ResourceLoader::preloadModuleInfo)). in
/www/translatewiki.net/w/includes/db/Database.php on line 4149

Based on this and comment 45, i would guess that remaining instances are probably mostly related to exception handling in load.php and update.php entry points (the update one is probably fine as is.)

I am seeing a very large number of these errors on my clustered MediaWiki instance. Something like 6000 errors per day per server (about 4 per minute.)

 7104 May 18
24986 May 19
24608 May 20
13899 May 21

All of them (a full 100%) report an uncommitted txn in the localization cache:

Uncommitted DB writes (transaction from DatabaseBase::query (LCStore_DB::get)).

I find this quite odd, as the LCStore_DB::get() method simply fetches something from the cache (the l10n_cache table in the database) and does no writing whatsoever. This might be a red-herring, though. Everything *seems* to be OK with the wiki installation, but I'm wary of these errors.

Any ideas?

(In reply to Daniel Renfro from comment #49)

All of them (a full 100%) report an uncommitted txn in the localization
cache:

To clarify, what's your [[mw:Manual:Cache]] config, is $wgCacheDirectory not set?

I'm using Memcached for the general object cache because I've got multiple webservers and would like to share stuff (including session-data) across all of them.

$wgMainCacheType = CACHE_MEMCACHED;
$wgMemCachedServers = array(  ...server list here...  );
$wgSessionsInObjectCache = true;

For the localization cache, everything is default. Of my reading from [[mw:Manual:$wgLocalisationCacheConf]], the localization cache layer should be using the database (which it looks like it is.)

I'm stumped.

Change 134662 had a related patch set uploaded by MarkAHershberger:
Avoid uncommitted transaction notices in thumb.php and img_auth.php

https://gerrit.wikimedia.org/r/134662

Change 134662 merged by jenkins-bot:
Avoid uncommitted transaction notices in thumb.php and img_auth.php

https://gerrit.wikimedia.org/r/134662

dnaslave wrote:

Don't know if this is same problem, but when I go to main page I get:
Internal error
[ff1c5836] 2014-05-28 18:54:15: Fatal exception of type MWException

and at the bottom: Notice: Uncommitted DB writes (transaction from DatabaseBase::query (WikiPage::pageData)). in /home/dwrice/uncool/wiki/includes/db/Database.php on line 3944

This started after I added Scribunto and the copied the Module:Citation/CS1/* pages from wikipedia

I'm getting these errors as of today in 1.22.5 when we try to delete an article. See my comment number 11 in bug 47375 for the error log, which includes both "Uncommitted DB writes" and "DB transaction callbacks still pending."

(In reply to Dan Barrett from comment #55)

I'm getting these errors as of today in 1.22.5 when we try to delete an
article. See my comment number 11 in bug 47375 for the error log, which
includes both "Uncommitted DB writes" and "DB transaction callbacks still
pending."

When did you install 1.22.5? What was installed before? If you install 1.22.7, does the problem disappear?

We installed 1.22.5 about a month ago. We did not experience problems with deletes until today, and the problem has gone away.

Before that, we had 1.21.x.

When we get a chance to install 1.22.7, I'll let you know what happens. (It's a production environment and we have to schedule these things.)

  • Bug 66311 has been marked as a duplicate of this bug. ***

Frequently getting this on 1.23.0, with WikiPage::pageData. Was getting it before on 1.22.x too.

bugzilla wrote:

I just got this error when I set $wgShowIPinHeader = false; in my LocalSettings.php. I'm on a brand new 1.23.1 install.
Maybe this info helps fixing the bug.

This is the error I get:
Notice: Uncommitted DB writes (transaction from DatabaseBase::query (LCStoreDB::get)). in /html/mw_test/mediawiki/includes/db/Database.php on line 4147

Aklapper renamed this task from Fix "Uncommitted DB writes (transaction from DatabaseBase::query)" to Uncommitted DB writes (transaction from DatabaseBase::query (Block::newLoad)).Jan 3 2015, 9:01 PM
Aklapper set Security to None.

It seems that sometime in the past a change was made to class DatabaseBase which either

  1. enabled transactions on queries that are called from the query() method
  2. disabled the implicit commit/rollback of queries called from the query() method

Unless the DatabaseBase::DBO_TRX flag is explicitly cleared after instantiating the class, a transaction is opened when calling query(). However, this open transaction is not automagically closed -- it's left to the user to call commit or rollback. In my 1.23.5 installation, I get errors like so:

Uncommitted DB writes (transaction from DatabaseBase::query (LCStore_DB::get)).

This seems to be because LCStore_DB::get calls DatabaseBase::selectRow --> DatabaseBase::select --> DatabaseBase::query which ends up in an uncommitted transaction.

Thanks, DanielRenfro. I confirm this error is still occurring daily on translatewiki.net.

Nemo_bis: Check if any of your extensions are calling $dbr->query("some SQL here") directly.

ack --type=php '\$db[rw]?->query\(' | wc -l
41

But that's not really relevant. We are not using LCStore_DB. @Bawolff might be right that this is related to exceptions being thrown and their handling.

I consistently get these notices on MW1.23 when $wgGroupPermissions['*']['read'] = false;

Removing from MW-1.24-release because this isn't going to be fixed in the next few months' worth of security point releases.

One of my extensions seems to be triggering this, and I have no idea what to do about it.

The extension basically follows the syntax at [[mw:Manual:Database access]], namely:

$dbw = wfGetDB( DB_MASTER );
$res = $dbw->select( ...some table... );
foreach( $res as $row ) {
	$dbw->update( ...some other table... );
}

There is nothing in the docs about needing to commit transactions you haven't started.

Is the fix no simply to add a commit() call at the end of query(), if it started an implicit transaction?

This is a very worrying message to be getting on production.

Note - problem started after upgrading from MW 1.18 to MW 1.25.2.

PS - What happened here:

(In reply to Krinkle from comment #28)

Recommending this block the 1.23.0 release.

Agreed.

We are now quite a few releases further down the line, and still no fix, or even (it appears) any attempt of a fix in core (as it seems to be a core bug, and so shouldn't require extensions to be updated to work round the issue).

I noticed some funny behavior wrt these uncommitted db writes notices. Like I reported earlier, I consistently see these notices for wikis (MW1.23) that require a login (i.e., are not readable for anonymous users). However, when I make the wiki temporarily publically accessible, access it through a browser and close it again, the notices disappear. When I 'touch' LocalSettings, the notices reappear. Cache invalidation seems to re-trigger the notices.

I've been hunting for a cause, and what I've found is that - in my case - disabling the following lines in OutputPage.php makes the notice disappear:

// Inline private modules. These can't be loaded through load.php for security
// reasons, see bug 34907. Note that these modules should be loaded from
// getHeadScripts() before the first loader call. Otherwise other modules can't
// properly use them as dependencies (bug 30914)
if ( $group === 'private' ) {
	if ( $only == ResourceLoaderModule::TYPE_STYLES ) {
		$links['html'] .= Html::inlineStyle(
			$resourceLoader->makeModuleResponse( $context, $grpModules )
		);
	} else {
		$links['html'] .= Html::inlineScript(
			ResourceLoader::makeLoaderConditionalScript(
				$resourceLoader->makeModuleResponse( $context, $grpModules )
			)
		);
	}
	$links['html'] .= "\n";
	continue;
}

I've followed the trace through resourceLoader::makeModuleReponse, and found out that my notices coincide with a REPLACE INTO query on the msg_resource table. Eventually, I ended up deeply in the database query code, so my trace ends here.

Can anyone verify whether disabling these lines in OutpuPage.php solves the issue for them too? Does anyone understand how these particular lines could trigger Uncommitted DB writes?

Suppose I leave these particular lines in OutputPage.php disabled, is there anything that can or will go wrong?

One of my extensions seems to be triggering this, and I have no idea what to do about it.

Could you do me a favor and see whether disabling the lines in OutputPage.php I just reported in my other comment fixes your issue? Yours may be entirely unrelated, but it's worth a shot.

Can anyone verify whether disabling these lines in OutpuPage.php solves the issue for them too? Does anyone understand how these particular lines could trigger Uncommitted DB writes?

I tried, and it failed.

One of my extensions seems to be triggering this, and I have no idea what to do about it.

Could you do me a favor and see whether disabling the lines in OutputPage.php I just reported in my other comment fixes your issue? Yours may be entirely unrelated, but it's worth a shot.

Typically, I can't seem to reproduce the error at the moment! It is obviously not part of the extension's core code-path, but I haven't yet worked out what events/actions trigger it.

If I manage to reproduce the error reliably then I will try disabling the above code to see if it helps. From my tentative diagnosis (above) I don't anticipate that it will, but that's only a hunch.

Will let you know if I'm able to reproduce or if I discover anything else useful.

Can anyone verify whether disabling these lines in OutpuPage.php solves the issue for them too?

Commenting those lines did not stop the Notices from my error.log

MediaWiki 1.26.4 (12a5963)
PHP 5.5.9-1ubuntu4.20 (apache2handler)
MySQL 5.5.53-0ubuntu0.14.04.1
ICU 52.1
Elasticsearch 2.3.4
Lua 5.1.5

Setting

$wgRunJobsAsync = false;

seems to have stopped the Notices... odd

Krinkle subscribed.

This task was about a transaction warning seen for in wmf-production as it happened from a Block action.

Transaction warnings in itself are not 1 bug. It's merely saying that something else went wrong. The original warning from prod has 0 hits in the last 7 days and has likely been fixed since then.

If you find this warning from a different code path on your own install, please file a new task. (Be sure to include steps to reproduce the warning, and if possible, a stack trace.)

mmodell changed the subtype of this task from "Task" to "Production Error".Aug 28 2019, 11:12 PM