Edgewall Software
Modify

Opened 4 years ago

Last modified 15 months ago

#12143 new defect

mysql + InnoDB + auth_cookie == Bad.

Reported by: branson@… Owned by:
Priority: normal Milestone:
Component: database backend Version: 1.0.8
Severity: major Keywords: mysql
Cc: Branch:
Release Notes:
API Changes:

Description (last modified by Jun Omae)

It appears that Trac using MySQL, InnoDB and the AccountManagerPlugin login page has a race condition with the auth_cookie table. This problem manifested itself when we migrated from sqlite to MySQL. While this uses the AccountManagerPlugin, the calls being used are w/in Trac proper:

  • trac/web/auth.py
  • trac/db/util.py
  • trac/db/mysql_backend.py

Configuration

  • database: MySQL and InnoDB tables
  • authentication using LDAP via AccountManagerPlugin
  • Configured to route user to '/trac/login' if there is not authentication

Test Case

  1. user logs in
  2. commit starts for auth_cookie update
  3. second thread looks for the cookie, doesn't find and expires the cookie
  4. user returned to login screen

I inserted quite a bit of logging to find this..

2015-07-27 16:49:29,097 Trac[util] DEBUG: SQL:
  INSERT INTO auth_cookie (cookie, name, ipnr, time) 
   VALUES (%s, %s, %s, %s)
2015-07-27 16:49:29,097 Trac[util] DEBUG: SQL args: ('cb4a763b891fa64c0ea38817226d39d6', u'branson', '172.16.20.34', 1438008569)
2015-07-27 16:49:29,098 Trac[util] DEBUG: SQL: completed, 1
2015-07-27 16:49:29,098 Trac[util] DEBUG: SQL: 
   DELETE FROM auth_cookie WHERE time < %s 
2015-07-27 16:49:29,099 Trac[util] DEBUG: SQL args: (1437144569,)
2015-07-27 16:49:29,099 Trac[util] DEBUG: SQL: completed, 0
2015-07-27 16:49:31,267 Trac[main] DEBUG: Dispatching <RequestWithSession "GET ''">
2015-07-27 16:49:31,275 Trac[util] DEBUG: SQL: 
   SELECT name FROM auth_cookie WHERE cookie=%s 
2015-07-27 16:49:31,275 Trac[util] DEBUG: SQL args: ('cb4a763b891fa64c0ea38817226d39d6',)
2015-07-27 16:49:31,276 Trac[util] DEBUG: SQL: completed, 0
2015-07-27 16:49:31,276 Trac[auth] DEBUG: no user found for cookie cb4a763b891fa64c0ea38817226d39d6 expiring it.

My read .. is the write is not completing before the read happens on a different thread and the read is returning 0 results.. so auth.py expires the cookie. This is because InnoDB does row level locking and we're doing a transaction, the update to the table does NOT lockout the read .. the read returns with 'old_Data' as designed in the case of a transaction, and therefore doesn't find the cookie.

I couldn't find a way to tell InnoDB to lock the table or row for read during update.. however to cheat.. I changed that one table to MyISAM which enforces table level locks for read on transaction and that resolved the problem ( I also had to comment out the error in db/mysql_backend.py for now )

According to https://dev.mysql.com/doc/refman/5.0/en/set-transaction.html#isolevel_read-committed this is standard behavior. There may be a way to cause serialized SELECT's against a locked table by setting autocommit=0 (bottom of that page)… however I want to see if this is a recommended way to resolve this issue.

Else I am not sure how/what can be used consistently if you can't block a table for read on a commit in this particular case.

Attachments (0)

Change History (3)

comment:1 by Ryan J Ollos, 4 years ago

Milestone: 1.0.9

Which version of Trac are you running?

comment:2 by branson@…, 4 years ago

1.0.8 .. tested on several versions prior and upgraded as I went to see if that may have resolved it.

comment:3 by Jun Omae, 3 years ago

Description: modified (diff)
Keywords: innodb transactions removed
Version: 1.0.8

Modify Ticket

Change Properties
Set your email in Preferences
Action
as new The ticket will remain with no owner.
The ticket will be disowned. Next status will be 'new'.
as The resolution will be set. Next status will be 'closed'.
The owner will be changed from (none) to anonymous. Next status will be 'assigned'.

Add Comment


E-mail address and name can be saved in the Preferences .
 
Note: See TracTickets for help on using tickets.