Page MenuHomePhabricator

SqlBagOStuff leaves open transactions on non-MySQL databases
Closed, ResolvedPublic

Description

When used with non-MySQL databases, SqlBagOStuff does not disable automatic transactions (DBO_TRX) and so can fail to commit the end-of-request save of session data when $wgSessionCacheType is CACHE_DB.

Original report:


I have MediaWiki 1.27.0 installed as a closed Wiki:
MediaWiki 1.27.0
PHP 5.6.20 (cgi-fcgi)
MS SQL Server 11.00.2100
IIS 7.5.7600
Windows 7 Enterprise, Servicepack 1, 64 Bit

In my own application (C#) I try to login using the API. First I fetch a login token and retrieve the cookies. Second I send a POST request with user, password, retrieved login token and retrieved cookies. The servers answer is NeedToken. When I try it outside of my application using Fiddler I have the same result:

  1. Request Fetch Login Token
GET http://localhost/mediawiki/api.php?action=query&meta=tokens&type=login&format=xml HTTP/1.1
User-Agent: Fiddler
Host: localhost
  1. Response
HTTP/1.1 200 OK
Cache-Control: private, must-revalidate, max-age=0
Content-Type: text/xml; charset=utf-8
Server: Microsoft-IIS/7.5
X-Powered-By: PHP/5.6.20
X-Content-Type-Options: nosniff
Set-Cookie: Wiki_Standard_session=2p9esdd8h5veh46r3mipvuuar30jkqkk; path=/; httponly
X-Frame-Options: DENY
X-Powered-By: ASP.NET
Date: Thu, 14 Jul 2016 07:44:23 GMT
Content-Length: 130

<?xml version="1.0"?><api batchcomplete=""><query><tokens logintoken="12fa822ce9b537b855989d6a179ce346578742d7+\" /></query></api>
  1. Request Login
POST http://localhost/mediawiki/api.php?action=login&format=xml HTTP/1.1
User-Agent: Fiddler
Host: localhost
Content-Type: application/x-www-form-urlencoded
Content-Length: 85
Cookie: Wiki_Standard_session=2p9esdd8h5veh46r3mipvuuar30jkqkk

lgname=wiki&lgpassword=***&lgtoken=12fa822ce9b537b855989d6a179ce346578742d7%2B%5C
  1. Response
HTTP/1.1 200 OK
Cache-Control: private, must-revalidate, max-age=0
Content-Type: text/xml; charset=utf-8
Server: Microsoft-IIS/7.5
X-Powered-By: PHP/5.6.20
X-Content-Type-Options: nosniff
X-Frame-Options: DENY
X-Powered-By: ASP.NET
Date: Thu, 14 Jul 2016 07:49:41 GMT
Content-Length: 359

<?xml version="1.0"?><api><warnings><login xml:space="preserve">Fetching a token via action=login is deprecated. Use action=query&amp;meta=tokens&amp;type=login instead.</login></warnings><login result="NeedToken" token="9082b41a22d33a9e0faf090edfd9672157874415+\" cookieprefix="Wiki_Standard" sessionid="2p9esdd8h5veh46r3mipvuuar30jkqkk" /></api>

I had a look into ApiQueryTokens.php, Session.php and ApiLogin.php. During the first request fetching the login token and the second request logging in is always the method getToken() of the class Session called. I made there some debug outputs seeing what’s wrong:

  1. Request Fetch Login Token
secrets: 

Session: sessionid=2p9esdd8h5veh46r3mipvuuar30jkqkk; Token: key=login, salt=, secret=2a28402e5c7d4f2c8464be81e9f85cab, new=1
  1. Request Login
secrets: 

Session: sessionid=2p9esdd8h5veh46r3mipvuuar30jkqkk; Token: key=login, salt=, secret=5d7b1d66014cde954aee9d83fad8b637, new=1

The sessionids are the same. The array $secrets from $this->get( 'wsTokenSecrets' ) is always empty. That’s why a new $secret and a new $token with the parameter $new = true will be created even during the second request where the $secret for the session should be exists. The check login token in the method execute() of class ApiLogin fails because the token of the session was just created ($token->wasNew()).

Event Timeline

The array $secrets from $this->get( 'wsTokenSecrets' ) is always empty.

You should figure out what's going wrong in your setup that is causing that to be the case. It would probably help to log at least the 'session' channel, and possibly also to enable debugging for whatever session storage is being used. To do the latter, you might put this in LocalSettings.php:

$wgHooks['SetupAfterCache'][] = function () {
    global $wgSessionCacheType;
    ObjectCache::getInstance( $wgSessionCacheType )->setDebug( true );
};

Thanks for support. Log file is uploaded.

Anomie added a subscriber: saper.
[error] [a8e86a840ced4899151816b4] [no req]   ErrorException from line 3303 of C:\inetpub\wwwroot\mediawiki\includes\db\Database.php: PHP Notice: Uncommitted DB writes (transaction from DatabaseBase::query (SqlBagOStuff::setMulti)).
#0 [internal function]: MWExceptionHandler::handleError(integer, string, string, integer, array)
#1 C:\inetpub\wwwroot\mediawiki\includes\db\Database.php(3303): trigger_error(string)
#2 [internal function]: DatabaseBase->__destruct()
#3 {main}

That's the problem, the database connection backing your SqlBagOStuff that's being used for session storage opened a transaction and didn't commit it.

When MySQL is being used, SqlBagOStuff disables auto-transactions so SqlBagOStuff works fine. But your log looks like you're using MSSQL:

[connect] Connected to database 0 at ***\MSSQLSERVER2012

Since @saper made the auto-transaction disabling only apply to MySQL (where previously it only didn't apply to SQLite) in rMW646a9490f74f: (bug 27283) SqlBagOStuff breaks PostgreSQL txns, pinging him. At a glance, it looks like the bug with SqlBagOStuff there was really that for some reason with PostgreSQL it wasn't getting a separate database connection, and that change only covered up the symptom.

Anomie renamed this task from API login responses NeedTooken to SqlBagOStuff leaves open transactions on non-MySQL databases.Jul 14 2016, 3:31 PM
Anomie updated the task description. (Show Details)

Change 366507 had a related patch set uploaded (by Krinkle; owner: Aaron Schulz):
[mediawiki/core@master] rdbms: Support secondary autocommit connections in LoadBalancer

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

Krinkle triaged this task as Medium priority.Aug 18 2017, 1:29 AM

Change 366507 merged by jenkins-bot:
[mediawiki/core@master] rdbms: Support secondary autocommit connections in LoadBalancer

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

Anomie assigned this task to aaron.

This looks like it was probably resolved by rMWf24b3899e383: objectcache: Use a separate postgres connection in SqlBagOStuff, with further refactoring in 99c80a8f. Feel free to reopen if that's not the case.