Page MenuHomePhabricator

Address "DB transaction callbacks still pending" warnings from Database.php
Closed, ResolvedPublicPRODUCTION ERROR

Description

Notice: Transaction idle or pre-commit callbacks still pending. in /usr/local/apache/common-local/php-1.22wmf2/includes/db/Database.php on line 3753


Version: 1.22.0
Severity: major
See Also:
https://bugzilla.wikimedia.org/show_bug.cgi?id=53341
https://bugzilla.wikimedia.org/show_bug.cgi?id=56124
https://bugzilla.wikimedia.org/show_bug.cgi?id=56269

Details

Reference
bz47375

Event Timeline

bzimport raised the priority of this task from to High.Nov 22 2014, 1:17 AM
bzimport set Reference to bz47375.
bzimport added a subscriber: Unknown Object (MLST).

At least the error should be made more useful.

Also seen on TWN: [23:13:07] -rakkaus:#mediawiki-i18n- [21-Apr-2013 20:13:44 UTC] PHP Notice: Transaction idle or pre-commit callbacks still pending. in /www/translatewiki.net/w/includes/db/Database.php on line 3755

This is exploding at translatewiki.net, 80 yesterday and 50 of the so far today.

Some debug info (credentials removed):

[13-Aug-2013 12:30:52 UTC] Array
(

[0] => Closure Object
    (
        [static] => Array
            (
                [dbw] => DatabaseMysql Object
                    (
                        [lastKnownSlavePos:protected] => 
                        [mLastQuery:protected] => SELECT  pp_value  FROM `bw_page_props`   WHERE pp_propname = 'use-liquid-threads' AND pp_page = '3402801'  LIMIT 1  
                        [mDoneWrites:protected] => 1
                        [mPHPError:protected] => 
                        [mServer:protected] => localhost
                        [mConn:protected] => Resource id #65
                        [mOpened:protected] => 1
                        [mTrxIdleCallbacks:protected] => Array

*RECURSION*

                    [mTrxPreCommitCallbacks:protected] => Array
                        (
                        )

                    [mTablePrefix:protected] => bw_
                    [mFlags:protected] => 24
                    [mTrxLevel:protected] => 1
                    [mErrorCount:protected] => 0
                    [mLBInfo:protected] => Array
                        (
                            [host] => localhost
                            [type] => mysql
                            [load] => 1
                            [flags] => 16
                            [serverIndex] => 0
                        )

                    [mFakeSlaveLag:protected] => 
                    [mFakeMaster:protected] => 
                    [mDefaultBigSelects:protected] => 
                    [mSchemaVars:protected] => 
                    [preparedArgs:protected] => 
                    [htmlErrors:protected] => 
                    [delimiter:protected] => ;
                    [mTrxFname:DatabaseBase:private] => DatabaseBase::query (WikiPage::pageData)
                    [mTrxDoneWrites:DatabaseBase:private] => 1
                    [mTrxAutomatic:DatabaseBase:private] => 1
                    [fileHandle:protected] => 
                )

            [method] => Block::purgeExpired
        )

)

)

Seems to be caused by spam bots trying to submit spam. Some examples:
a:2:{s:5:"title";s:47:"Property_Occasion_Plan_Business_Time-Management";s:6:"action";s:4:"edit";}
a:2:{s:5:"title";s:31:"Internet_Marketing_Distribution";s:6:"action";s:4:"edit";}
a:2:{s:5:"title";s:48:"Tips_On_Getting_To_Grips_With_Internet_Marketing";s:6:"action";s:4:"edit";}

New message which seems most likely this same bug:
2013-10-23 10.04 -rakkaus:#mediawiki-i18n- [23-Oct-2013 08:04:11 UTC] PHP Notice: Uncommitted DB writes (transaction from DatabaseBase::query (Title::getCascadeProtectionSources)). in /www/translatewiki.net/w/includes/db/Database.php on line 3904

13 times in total so far (yesterday and today) after

2013-10-23 9.10 -rakkaus:#mediawiki-i18n- [siebrand] updated translatewiki.net to 0ea06c7 2013-10-23 07:10:33 +0000 (2 seconds ago)

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

Maybe relevant? From MediaWiki-General:

<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

There are four different code paths emitting this type of notice:

@ class Database
public function close() {
if ( count( $this->mTrxIdleCallbacks ) ) {

		throw new MWException( "Transaction idle callbacks still pending." );

...

@ class Database
public function close() {
...
if ( $this->mConn &&

		$this->trxLevel() &&
		!$this->mTrxAutomatic

) {

		wfWarn( "Transaction still in progress (from {$this->mTrxFname}), " .
		" performing implicit commit before closing connection!" );

...

@ class Database
public function __destruct() {
if ( $this->mTrxLevel && $this->mTrxDoneWrites ) {

		trigger_error( "Uncommitted DB writes (transaction from {$this->mTrxFname})." );

...

@ class Database
public function __destruct() {
...
if ( count( $this->mTrxIdleCallbacks ) || count( $this->mTrxPreCommitCallbacks ) ) {

		...
		trigger_error( "DB transaction callbacks still pending (from $callers)." );

...

I am also experiencing this problem (see mediawiki-l post http://lists.wikimedia.org/pipermail/mediawiki-l/2014-January/042329.html) and have some additional data.

I installed the same 1.22.0 codebase and database on two different Linux servers. Server #1 has PHP 5.5.3 and mySQL 5.5.34), and serer #2 has PHP 5.3.27 and mySQL 5.1.68. Server #2 has the problem and server #1 does not.

On server #1, I deployed 1.22.0 and copied my /images and LocalSettings.php files from 1.21.3, then ran update.php. Everything worked. I copied the same files to server #2, ran update.php, and saw no errors.

Then I hit the main page (whatever.com/wiki/Home) as an anonymous user.
When the home page rendered, it had this error message printed at the bottom:

Notice: Uncommitted DB writes (transaction from DatabaseBase::query (WikiPage::pageData)).
in ...../w/includes/db/Database.php on line 3944

I clicked "Log In", and the home page just sat there. Running a "ps uax" I saw these processes:

me 16283 0.5 1.0 160180 43948 ? S 23:45 0:00 /usr/bin/php /home/me/public_html/w/index.php
me 16286 0.0 0.0 0 0 ? Z 23:45 0:00 [bash] <defunct>
me 16287 0.0 0.4 134764 17532 ? S 23:45 0:00 /usr/bin/php /home/me/public_html/w/maintenance/runJobs.php --maxjobs 1
me 16295 0.4 1.0 160036 43856 ? S 23:45 0:00 /usr/bin/php /home/me/public_html/w/index.php
me 16296 0.0 0.0 0 0 ? Z 23:45 0:00 [bash] <defunct>
me 16297 0.1 0.4 134764 17544 ? S 23:45 0:00 /usr/bin/php /home/me/public_html/w/maintenance/runJobs.php --maxjobs 1
me 16847 0.1 0.4 87388 17468 ? S 23:46 0:00 /usr/bin/php /home/me/public_html/w/index.php
me 16856 0.1 0.4 87388 17480 ? S 23:46 0:00 /usr/bin/php /home/me/public_html/w/index.php
me 16878 0.1 0.4 87388 17468 ? S 23:46 0:00 /usr/bin/php /home/me/public_html/w/index.php

I checked the job queue with maintenance/showJobs.php, and there were 0 jobs.

The processes were not exiting (my browser was still spinning), so I killed them by hand.

Still baffled about what to do.

I've been getting these in 1.22.5 when trying to delete an article. The delete fails with:

"A database query error has occurred. This may indicate a bug in the software."

and in the logs:

[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP Notice: Uncommitted DB writes (transaction from WikiPage::doDeleteArticleReal). in /mnt/mywiki/w/includes/db/Database.php on line 3944, referer: http://mywiki.mysite.net/w/index.php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP Stack trace:, referer: http://mywiki.mysite.net/w/index.php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 1. {main}() /mnt/mywiki/w/index.php:0, referer: http://mywiki.mysite.net/w/index.php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 2. MediaWiki->run() /mnt/mywiki/w/index.php:65, referer: http://mywiki.mysite.net/w/index.php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 3. MWExceptionHandler::handle() /mnt/mywiki/w/includes/Wiki.php:470, referer: http://mywiki.mysite.net/w/index.php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 4. DatabaseBase->destruct() /mnt/mywiki/w/includes/db/Database.php:0, referer: http://mywiki.mysite.net/w/index.php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 5. trigger_error() /mnt/mywiki/w/includes/db/Database.php:3944, referer: http://mywiki.mysite.net/w/index.php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP Notice: DB transaction callbacks still pending (from Title::invalidateCache, HTMLCacheUpdate::doUpdate, EmailNotification::notifyOnPageChange). in /mnt/mywiki/w/includes/db/Database.php on line 3953, referer: http://mywiki.mysite.net/w/index.php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP Stack trace:, referer: http://mywiki.mysite.net/w/index.php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 1. {main}() /mnt/mywiki/w/index.php:0, referer: http://mywiki.mysite.net/w/index.php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 2. MediaWiki->run() /mnt/mywiki/w/index.php:65, referer: http://mywiki.mysite.net/w/index.php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 3. MWExceptionHandler::handle() /mnt/mywiki/w/includes/Wiki.php:470, referer: http://mywiki.mysite.net/w/index.php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 4. DatabaseBase->
destruct() /mnt/mywiki/w/includes/db/Database.php:0, referer: http://mywiki.mysite.net/w/index.php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 5. trigger_error() /mnt/mywiki/w/includes/db/Database.php:3953, referer: http://mywiki.mysite.net/w/index.php?title=How_to_add_the_redacted&action=delete

This warning should go away, and be thrown only when $wgDevelopmentWarnings is set to true.

Otherwise, many errors get masked by this one, since the "original" error happens, and then when MediaWiki closes the connection, throws this one because the "original" error prevented the commit or rollback.

This warning is useless in production environments!

(In reply to Dan Barrett from comment #11)

I've been getting these in 1.22.5 when trying to delete an article. The
delete fails with:

"A database query error has occurred. This may indicate a bug in the
software."

and in the logs:

[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP Notice:
Uncommitted DB writes (transaction from WikiPage::doDeleteArticleReal). in
/mnt/mywiki/w/includes/db/Database.php on line 3944, referer:
http://mywiki.mysite.net/w/index.
php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP Stack trace:,
referer:
http://mywiki.mysite.net/w/index.
php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 1. {main}()
/mnt/mywiki/w/index.php:0, referer:
http://mywiki.mysite.net/w/index.
php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 2.
MediaWiki->run() /mnt/mywiki/w/index.php:65, referer:
http://mywiki.mysite.net/w/index.
php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 3.
MWExceptionHandler::handle() /mnt/mywiki/w/includes/Wiki.php:470, referer:
http://mywiki.mysite.net/w/index.
php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 4.
DatabaseBase->destruct() /mnt/mywiki/w/includes/db/Database.php:0,
referer:
http://mywiki.mysite.net/w/index.
php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 5.
trigger_error() /mnt/mywiki/w/includes/db/Database.php:3944, referer:
http://mywiki.mysite.net/w/index.
php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP Notice: DB
transaction callbacks still pending (from Title::invalidateCache,
HTMLCacheUpdate::doUpdate, EmailNotification::notifyOnPageChange). in
/mnt/mywiki/w/includes/db/Database.php on line 3953, referer:
http://mywiki.mysite.net/w/index.
php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP Stack trace:,
referer:
http://mywiki.mysite.net/w/index.
php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 1. {main}()
/mnt/mywiki/w/index.php:0, referer:
http://mywiki.mysite.net/w/index.
php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 2.
MediaWiki->run() /mnt/mywiki/w/index.php:65, referer:
http://mywiki.mysite.net/w/index.
php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 3.
MWExceptionHandler::handle() /mnt/mywiki/w/includes/Wiki.php:470, referer:
http://mywiki.mysite.net/w/index.
php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 4.
DatabaseBase->
destruct() /mnt/mywiki/w/includes/db/Database.php:0,
referer:
http://mywiki.mysite.net/w/index.
php?title=How_to_add_the_redacted&action=delete
[Fri May 30 11:20:45 2014] [error] [client 11.22.33.44] PHP 5.
trigger_error() /mnt/mywiki/w/includes/db/Database.php:3953, referer:
http://mywiki.mysite.net/w/index.
php?title=How_to_add_the_redacted&action=delete

Have you more info about PHP/Database (like MySQL) version, installed extensions, etc?

MediaWiki 1.22.5 on a cluster with 3 front-end web servers through a load-balancer, and 2 database servers (one master replicating to one slave)

mysql Ver 14.14 Distrib 5.5.37

Over 120 extensions, most of them custom-built. It's a production environment and we can't turn off extensions. The problem has never appeared in any of our (non-clustered) test environments, only on the production cluster.

Correction to comment 14: three database servers, one master replicating to 2 slaves. (However, one of the slaves is not accessed by users... it's just for reporting purposes.)

Happy to answer more questions and try things out.

This warning should go away, and be thrown only when $wgDevelopmentWarnings is set to true.

Otherwise, many errors get masked by this one, since the "original" error happens, and then when MediaWiki closes the connection, throws this one because the "original" error prevented the commit or rollback.

This warning is useless in production environments!

Task proposed in T85762: Get rid of the Uncommitted DB writes notice

demon lowered the priority of this task from High to Medium.Jun 11 2015, 4:20 PM
demon raised the priority of this task from Medium to High.
demon subscribed.
demon lowered the priority of this task from High to Medium.Jun 11 2015, 4:39 PM
Krinkle claimed this task.

Closing. All references bugs about individual issues were solved. I don't think a tracking bug would be useful for this particular group of errors.

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