Audilog generating Deadlocks in log_create function with high volume of requests

[edilio]

We use auditlog in a high traffic site using MySql(PyMySQL==0.7.9 and Gevent) and it is giving us Deadlocks:

InternalError: (1213, u'Deadlock found when trying to get lock; try restarting transaction')

Please, could you retry for three times using something like this?:

import time 

from django.db import OperationalError

class DeadLockFreeManager(models.Manager):
    
    def create(self, **kwargs):
        attempts = 0
        while attempts < 3:
            try:
                return super(DeadLockFreeManager, self).create(**kwargs)
            except OperationalError as e:
                code = e.args[0]
                if attempts == 2 or code != 1213:
                    raise e
                attempts += 1
                time.sleep(0.2)
                

class LogEntryManager(DeadLockFreeManager):

As you can see in the Deadlock is created in log_create function when it is trying to create the record:

return self.create(**kwargs)

Sorry I haven't test the code yet but I hope I am giving enough information to fix the issue.

Stack trace:

File "/usr/local/lib/python2.7/dist-packages/auditlog/receivers.py", line 21, in log_create
   changes=json.dumps(changes),
 File "/usr/local/lib/python2.7/dist-packages/auditlog/models.py", line 56, in log_create
   return self.create(**kwargs)
 File "/usr/local/lib/python2.7/dist-packages/django/db/models/manager.py", line 127, in manager_method
   return getattr(self.get_queryset(), name)(*args, **kwargs)
 File "/usr/local/lib/python2.7/dist-packages/django/db/models/query.py", line 348, in create
   obj.save(force_insert=True, using=self.db)
 File "/usr/local/lib/python2.7/dist-packages/django/db/models/base.py", line 734, in save
   force_update=force_update, update_fields=update_fields)
 File "/usr/local/lib/python2.7/dist-packages/django/db/models/base.py", line 762, in save_base
   updated = self._save_table(raw, cls, force_insert, force_update, using, update_fields)
 File "/usr/local/lib/python2.7/dist-packages/django/db/models/base.py", line 846, in _save_table
   result = self._do_insert(cls._base_manager, using, fields, update_pk, raw)
 File "/usr/local/lib/python2.7/dist-packages/django/db/models/base.py", line 885, in _do_insert
   using=using, raw=raw)
 File "/usr/local/lib/python2.7/dist-packages/django/db/models/manager.py", line 127, in manager_method
   return getattr(self.get_queryset(), name)(*args, **kwargs)
 File "/usr/local/lib/python2.7/dist-packages/django/db/models/query.py", line 920, in _insert
   return query.get_compiler(using=using).execute_sql(return_id)
 File "/usr/local/lib/python2.7/dist-packages/django/db/models/sql/compiler.py", line 974, in execute_sql
   cursor.execute(sql, params)
 File "/usr/local/lib/python2.7/dist-packages/django/db/backends/utils.py", line 64, in execute
   return self.cursor.execute(sql, params)
 File "/usr/local/lib/python2.7/dist-packages/django/db/utils.py", line 98, in __exit__
   six.reraise(dj_exc_type, dj_exc_value, traceback)
 File "/usr/local/lib/python2.7/dist-packages/django/db/backends/utils.py", line 64, in execute
   return self.cursor.execute(sql, params)
 File "/usr/local/lib/python2.7/dist-packages/django/db/backends/mysql/base.py", line 124, in execute
   return self.cursor.execute(query, args)
 File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 134, in execute
   result = self._query(query)
 File "/usr/local/lib/python2.7/dist-packages/pymysql/cursors.py", line 282, in _query
   conn.query(q)
 File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 768, in query
   self._affected_rows = self._read_query_result(unbuffered=unbuffered)
 File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 929, in _read_query_result
   result.read()
 File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1125, in read
   first_packet = self.connection._read_packet()
 File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 893, in _read_packet
   packet.check_error()
 File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 369, in check_error
   err.raise_mysql_exception(self._data)
 File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 120, in raise_mysql_exception
   _check_mysql_exception(errinfo)
 File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 115, in _check_mysql_exception
   raise InternalError(errno, errorvalue)
InternalError: (1213, u'Deadlock found when trying to get lock; try restarting transaction')

[jjkester]

Deadlocks indeed can occur on high traffic databases due to locking strategies. I am not in favour of just retrying - I might investigate on this issue and read up on common fixes for Django.

On another project I encountered a similar error which turned out to be due to inefficient use of the database (using atomic transactions solved it). You might look into that as well.

Nevertheless, a solution should be found. Thanks for reporting.