django-silk icon indicating copy to clipboard operation
django-silk copied to clipboard

MySQL can deadlock on garbage collection

Open albertyw opened this issue 6 years ago • 10 comments

...
/silk/models.py", line 167, in save
    Request.garbage_collect(force=False)
/silk/models.py", line 152, in garbage_collect
    cls.objects.filter(start_time__lte=time_cutoff).delete()
...
/silk/sql.py", line 45, in execute_sql
    return self._execute_sql(*args, **kwargs)
...
django.db.utils.OperationalError: (1213, 'Deadlock found when trying to get lock; try restarting transaction')

albertyw avatar Jul 09 '18 03:07 albertyw

Experienced similar issue with PostgreSQL. Silk v.3.0.1, Django 1.11.13 Here are the details from Sentry:

TransactionRollbackError: deadlock detected
DETAIL:  Process 15422 waits for ShareLock on transaction 6038563; blocked by process 15420.
Process 15420 waits for AccessExclusiveLock on tuple (247,8) of relation 148876 of database 16384; blocked by process 15421.
Process 15421 waits for ShareLock on transaction 6038573; blocked by process 15422.
HINT:  See server log for query details.
CONTEXT:  while deleting tuple (404,8) in relation "silk_response"

  File "django/db/backends/utils.py", line 64, in execute
    return self.cursor.execute(sql, params)

OperationalError: deadlock detected
DETAIL:  Process 15422 waits for ShareLock on transaction 6038563; blocked by process 15420.
Process 15420 waits for AccessExclusiveLock on tuple (247,8) of relation 148876 of database 16384; blocked by process 15421.
Process 15421 waits for ShareLock on transaction 6038573; blocked by process 15422.
HINT:  See server log for query details.
CONTEXT:  while deleting tuple (404,8) in relation "silk_response"

  File "django/core/handlers/exception.py", line 41, in inner
    response = get_response(request)
  File "django/utils/deprecation.py", line 138, in __call__
    response = self.process_request(request)
  File "silk/middleware.py", line 96, in process_request
    request_model = RequestModelFactory(request).construct_request_model()
  File "silk/model_factory.py", line 191, in construct_request_model
    body=body)
  File "django/db/models/manager.py", line 85, in manager_method
    return getattr(self.get_queryset(), name)(*args, **kwargs)
  File "django/db/models/query.py", line 394, in create
    obj.save(force_insert=True, using=self.db)
  File "silk/models.py", line 167, in save
    Request.garbage_collect(force=False)
  File "silk/models.py", line 152, in garbage_collect
    cls.objects.filter(start_time__lte=time_cutoff).delete()
  File "django/db/models/query.py", line 620, in delete
    deleted, _rows_count = collector.delete()
  File "django/db/models/deletion.py", line 284, in delete
    count = qs._raw_delete(using=self.using)
  File "django/db/models/query.py", line 634, in _raw_delete
    return sql.DeleteQuery(self.model).delete_qs(self, using)
  File "django/db/models/sql/subqueries.py", line 80, in delete_qs
    cursor = self.get_compiler(using).execute_sql(CURSOR)
  File "silk/sql.py", line 45, in execute_sql
    return self._execute_sql(*args, **kwargs)
  File "django/db/models/sql/compiler.py", line 899, in execute_sql
    raise original_exception
  File "django/db/models/sql/compiler.py", line 889, in execute_sql
    cursor.execute(sql, params)
  File "raven/contrib/django/client.py", line 123, in execute
    return real_execute(self, sql, params)
  File "django/db/backends/utils.py", line 64, in execute
    return self.cursor.execute(sql, params)
  File "django/db/utils.py", line 94, in __exit__
    six.reraise(dj_exc_type, dj_exc_value, traceback)
  File "django/utils/six.py", line 685, in reraise
    raise value.with_traceback(tb)
  File "django/db/backends/utils.py", line 64, in execute
    return self.cursor.execute(sql, params)```

meequz avatar Oct 08 '18 14:10 meequz

Same issue with PostgreSQL 9.6, Django 2.0.6 and silk 3.0.1

helloagain-dev avatar Nov 26 '18 22:11 helloagain-dev

Same issue with MariaDB 5.5.60, Django 2.1.9 and silk 3.0.2

kashewnuts avatar Jun 26 '19 05:06 kashewnuts

I don't see why this doesn't get more attention. In my opinion this is a serious issue which prevents us from using Silk. Are there any workarounds I am missing?

helloagain-dev avatar Jun 26 '19 07:06 helloagain-dev

Same issue with PostgreSQL 10.6 and Django 2.2

makarovstas avatar Jul 02 '19 15:07 makarovstas

Same issue with Django 2.2, PostgreSQL 9.6.11 and silk 3.0.2

ot4kon avatar Aug 28 '19 11:08 ot4kon

Same issue with Django 2.2, MySQL 5.7 and silk 4.1.0

idealatom avatar Sep 22 '20 08:09 idealatom

Funny thing, the issue #294 and #371 are in a deadlock???

R-Future avatar Dec 21 '20 02:12 R-Future

also experiencing this in postgresql, but commenting here as #371 is closed as duplicate and it looks like this has been an issue before as documented in #265 - the workaround mentioned in https://github.com/jazzband/django-silk/issues/265#issuecomment-705482767 might be the most robust approach right now

using django-silk 4.2.0

nschlemm avatar Jan 21 '22 09:01 nschlemm

One possible solution is to use select_for_update to lock the rows before deletion, using skip_locked=True

SebCorbin avatar Oct 27 '22 21:10 SebCorbin