Deadlock on MySQL when purging old anonymous sessions in Session.save()

[Jun Omae]

I've got deadlocks with MySQL under production environment.

Traceback (most recent call last):
  File "/venv/lib/python2.6/site-packages/trac/web/main.py", line 567, in _dispatch_request
    dispatcher.dispatch(req)
  File "/venv/lib/python2.6/site-packages/trac/web/main.py", line 270, in dispatch
    req.send(output, content_type or 'text/html')
  File "/venv/lib/python2.6/site-packages/trac/web/api.py", line 550, in send
    self.send_response(status)
  File "/venv/lib/python2.6/site-packages/trac/web/main.py", line 102, in send_response
    self.session.save()
  File "/venv/lib/python2.6/site-packages/trac/web/session.py", line 187, in save
    """, (mintime,))
  File "/venv/lib/python2.6/site-packages/trac/db/util.py", line 128, in execute
    cursor.execute(query, params if params is not None else [])
  File "/venv/lib/python2.6/site-packages/trac/db/util.py", line 72, in execute
    return self.cursor.execute(sql_escape_percent(sql), args)
  File "/venv/lib/python2.6/site-packages/MySQLdb/cursors.py", line 205, in execute
    self.errorhandler(self, exc, value)
  File "/venv/lib/python2.6/site-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
    raise errorclass, errorvalue
OperationalError: (1213, 'Deadlock found when trying to get lock; try restarting transaction')

Deleting old anonymous sessions between 2 transactions in the same time leads the deadlock.

*** (1) TRANSACTION:
TRANSACTION 0 813950056, ACTIVE 0 sec, process no 9791, OS thread id 139812286813952 starting index read
mysql tables in use 2, locked 2
LOCK WAIT 6 lock struct(s), heap size 1216, 4 row lock(s), undo log entries 3
MySQL thread id 15761050, query id 1582491217 10.0.1.30 tracuser updating
DELETE FROM session_attribute
                      WHERE authenticated=0 AND sid IN (
                          SELECT sid FROM session
                          WHERE authenticated=0 AND last_visit < 1502759550
                      )

*** (2) TRANSACTION:
TRANSACTION 0 813950055, ACTIVE 0 sec, process no 9791, OS thread id 139812289476352 fetching rows, thread declared inside InnoDB 80
mysql tables in use 2, locked 2
50 lock struct(s), heap size 6752, 3474 row lock(s), undo log entries 3
MySQL thread id 15761048, query id 1582491213 10.0.1.30 tracuser updating
DELETE FROM session_attribute
                      WHERE authenticated=0 AND sid IN (
                          SELECT sid FROM session
                          WHERE authenticated=0 AND last_visit < 1502759550
                      )

The delete query is full scan on session_attribute table.

mysql> EXPLAIN DELETE FROM session_attribute
    -> WHERE authenticated=0 AND sid IN (
    ->   SELECT sid FROM session
    ->   WHERE authenticated=0
    ->   AND last_visit < 1502759550);
+----+--------------------+-------------------+-----------------+----------------------------------------------------------+---------+---------+------------+--------+-------------+
| id | select_type        | table             | type            | possible_keys                                            | key     | key_len | ref        | rows   | Extra       |
+----+--------------------+-------------------+-----------------+----------------------------------------------------------+---------+---------+------------+--------+-------------+
|  1 | PRIMARY            | session_attribute | ALL             | NULL                                                     | NULL    | NULL    | NULL       | 232569 | Using where |
|  2 | DEPENDENT SUBQUERY | session           | unique_subquery | PRIMARY,session_last_visit_idx,session_authenticated_idx | PRIMARY | 506     | func,const |      1 | Using where |
+----+--------------------+-------------------+-----------------+----------------------------------------------------------+---------+---------+------------+--------+-------------+
2 rows in set (0.00 sec)