Page MenuHomePhabricator

SavepointPostgres tries to rollback already committed/rolled back transactions
Closed, ResolvedPublic

Description

Author: overlordq

Description:

php phpunit.php --configuration /var/www/thedarkcitadel.com/w/tests/phpunit/suite.xml --exclude-group Parser,Broken,ParserFuzz,Stub
PHPUnit 3.6.11 by Sebastian Bergmann.

Configuration read from /var/www/thedarkcitadel.com/w/tests/phpunit/suite.xml

PHP Notice: DatabaseBase::rollback: No transaction to rollback, something got out of sync! [Called from DatabaseBase::rollback in /var/www/thedarkcitadel.com/w/includes/db/Database.php at line 3088] in /var/www/thedarkcitadel.com/w/includes/debug/Debug.php on line 283

Notice: DatabaseBase::rollback: No transaction to rollback, something got out of sync! [Called from DatabaseBase::rollback in /var/www/thedarkcitadel.com/w/includes/db/Database.php at line 3088] in /var/www/thedarkcitadel.com/w/includes/debug/Debug.php on line 283
PHP Notice: DatabaseBase::rollback: No transaction to rollback, something got out of sync! [Called from DatabaseBase::rollback in /var/www/thedarkcitadel.com/w/includes/db/Database.php at line 3088] in /var/www/thedarkcitadel.com/w/includes/debug/Debug.php on line 283

Notice: DatabaseBase::rollback: No transaction to rollback, something got out of sync! [Called from DatabaseBase::rollback in /var/www/thedarkcitadel.com/w/includes/db/Database.php at line 3088] in /var/www/thedarkcitadel.com/w/includes/debug/Debug.php on line 283
PHP Notice: DatabaseBase::rollback: No transaction to rollback, something got out of sync! [Called from DatabaseBase::rollback in /var/www/thedarkcitadel.com/w/includes/db/Database.php at line 3088] in /var/www/thedarkcitadel.com/w/includes/debug/Debug.php on line 283

Notice: DatabaseBase::rollback: No transaction to rollback, something got out of sync! [Called from DatabaseBase::rollback in /var/www/thedarkcitadel.com/w/includes/db/Database.php at line 3088] in /var/www/thedarkcitadel.com/w/includes/debug/Debug.php on line 283

make: *** [noparser] Segmentation fault


Version: 1.21.x
Severity: major

Details

Reference
bz44136

Related Objects

View Standalone Graph
This task is connected to more than 200 other tasks. Only direct parents and subtasks are shown here. Use View Standalone Graph to show more of the graph.

Event Timeline

bzimport raised the priority of this task from to Medium.Nov 22 2014, 1:26 AM
bzimport added a project: Wikimedia-Rdbms.
bzimport set Reference to bz44136.
bzimport added a subscriber: Unknown Object (MLST).

overlordq wrote:

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

overlordq wrote:

Trying to get a backtrace from rollback() was semi-successful, steps past #5 contain way to much data for use. I'll attach what I can. Give that part of the stack includes SavepointPostgres makes me lead to the belief that is is Pg only, and the txlevel is probably not being cleared/set correctly on rollback/commits.

overlordq wrote:

Backtrace from DatabaseBase->rollback context

Attached:

overlordq wrote:

Alright, I think I know the issue.

On line 817 of DatabasePostgres[1] we explicitly call $savepoint->commit() if we have a savepoint,

SavepointPostgres::commit calls the commit function of the originally passed database handle. This isn't defined IN DatabasePostgres so it uses DatabaseBase::commit which calls DatabaseBase::doCommit which clears out the mTrxLevel and does a 'COMMIT' query.

Then after we return on 837 of DatabasePostgres $savepoint moves out of scope and so it's __destruct method is called.

SavepointPostgres::__destruct only checks $this->didbegin and not against $dbw->trxLevel().

In the DatabasePostgres::insert function the savepoint is initialized before the query method, and so in the context of SavepointPostgres::__construct there is no trxLevel yes, and thus sets didbegin.

So when __destruct is called, it calls $dbw->rollback() which throws the error that there is No transaction to rollback as DatabaseBase::commit already committed the transaction.

tl;dr SavepointPostgres::__destruct only checks to see if we started a transaction and not if we're still in one and tries to rollback out of transaction.

It seems bugzilla wont let me CC saper as it's his code, so I will pester on IRC.

1 - https://gerrit.wikimedia.org/r/gitweb?p=mediawiki/core.git;a=blame;f=includes/db/DatabasePostgres.php;hb=c15d0a7521231c2cb71e664265e08d0ae514fc73#l817

Here's saper:)

No code is mine :) Before looking into it, quick question:

  • what are your cache settings? ($wgMainCacheType and friends?)
  • can you have an output from $wgDebugLogFile with $wgDebugDBTransactions enabled?

I get similar problems mostly when something other is accessing database independently and playing with transactions on its own (see bug 27283 for example).

Ok, I think that the problem is because we should reset "didbegin" to false once we commit or rollback the transaction in the context of SavepointPostgres. I just wonder what has changed since this code was introduced. Did INSERT has its own enclosing transaction before, so SavepointPostgres never introduced its own?

overlordq wrote:

SQL statement logging.

I keep forgetting with gerrit committer may not equal author.

Cache is CACHE_ACCEL.

Debug Log doesn't have anything helpful in it.

Attached:

overlordq wrote:

Debug Log

Attached:

Thanks, I think I have an easy fix for this.

By the way, there is information in the logs that phpunit.php dumps core at the end. Can you get more information about it like a stackgrace using "gdb <pathtophp> php.core" or something? It might be some instance of bug 43972 and we are still looking for more information about it and we are grateful for infos :)

Some preliminary and untested fix in gerrit change 45231

Merged by Demon on the 31st. Can someone test this?

In that case, let's mark this as resolved.

Jdforrester-WMF added a subscriber: Jdforrester-WMF.

Migrating from the old tracking task to a tag for PostgreSQL-related tasks.