Opened 5 months ago

Last modified 4 months ago

#36318 assigned Bug

Bad stack trace during rollback after bulk create — at Version 2

Reported by: Gordon Wrigley Owned by:
Component: Database layer (models, ORM) Version: 4.2
Severity: Normal Keywords:
Cc: Triage Stage: Accepted
Has patch: yes Needs documentation: yes
Needs tests: no Patch needs improvement: no
Easy pickings: no UI/UX: no

Description (last modified by Gordon Wrigley)

The value of connection.rollback_exc is being set in one transaction and then raised in a different later, unrelated transaction.

with these models

class Firm(Model):
    name = models.CharField(max_length=255, unique=True)

class Lender(Model):
    name = models.CharField(max_length=255, unique=True)
    override_svr = models.DecimalField(max_digits=6, decimal_places=2)

this code

def bob():
    try:
        with transaction.atomic():
            Firm.objects.create(name="bob")
            Firm.objects.create(name="bob")
    except Exception as e:
        pass # safely ignoring e

def fred():
    with transaction.atomic():
        try:
            l = Lender(name="fred", override_svr = "bobit")
            Lender.objects.bulk_create([l])
        except Exception as e:
            pass # unsafely ignoring e

        Lender.objects.count() # will fail because we're in a broken transaction

def main():
    try:
        bob()
        Lender.objects.count() # demonstrate we can make queries
        fred()
    except Exception as e:
        import traceback
        traceback.print_exc()


main()

yields this exception

Traceback (most recent call last):
  django/db/backends/utils.py", line 89, in _execute
    return self.cursor.execute(sql, params)
psycopg2.errors.UniqueViolation: duplicate key value violates unique constraint "retain_firm_name_key"
DETAIL:  Key (name)=(bob) already exists.


The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "<ipython-input-6-729c3e87d98c>", line 9, in bob
    Firm.objects.create(name="bob")
  django/db/models/manager.py", line 87, in manager_method
    return getattr(self.get_queryset(), name)(*args, **kwargs)
  django/db/models/query.py", line 658, in create
    obj.save(force_insert=True, using=self.db)
  django/db/models/base.py", line 814, in save
    self.save_base(
  django/db/models/base.py", line 877, in save_base
    updated = self._save_table(
  django/db/models/base.py", line 1020, in _save_table
    results = self._do_insert(
  django/db/models/base.py", line 1061, in _do_insert
    return manager._insert(
  django/db/models/manager.py", line 87, in manager_method
    return getattr(self.get_queryset(), name)(*args, **kwargs)
  django/db/models/query.py", line 1805, in _insert
    return query.get_compiler(using=using).execute_sql(returning_fields)
  django/db/models/sql/compiler.py", line 1822, in execute_sql
    cursor.execute(sql, params)
  django/db/backends/utils.py", line 102, in execute
    return super().execute(sql, params)
  django/db/backends/utils.py", line 67, in execute
    return self._execute_with_wrappers(
  django/db/backends/utils.py", line 80, in _execute_with_wrappers
    return executor(sql, params, many, context)
  django/db/backends/utils.py", line 84, in _execute
    with self.db.wrap_database_errors:
  django/db/utils.py", line 91, in __exit__
    raise dj_exc_value.with_traceback(traceback) from exc_value
  django/db/backends/utils.py", line 89, in _execute
    return self.cursor.execute(sql, params)
django.db.utils.IntegrityError: duplicate key value violates unique constraint "retain_firm_name_key"
DETAIL:  Key (name)=(bob) already exists.


The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "<ipython-input-6-729c3e87d98c>", line 27, in main
    fred()
  File "<ipython-input-6-729c3e87d98c>", line 21, in fred
    Lender.objects.count() # will fail because we're in a broken transaction
  django/db/models/manager.py", line 87, in manager_method
    return getattr(self.get_queryset(), name)(*args, **kwargs)
  django/db/models/query.py", line 608, in count
    return self.query.get_count(using=self.db)
  django/db/models/sql/query.py", line 568, in get_count
    return obj.get_aggregation(using, {"__count": Count("*")})["__count"]
  django/db/models/sql/query.py", line 554, in get_aggregation
    result = compiler.execute_sql(SINGLE)
  django/db/models/sql/compiler.py", line 1562, in execute_sql
    cursor.execute(sql, params)
  django/db/backends/utils.py", line 102, in execute
    return super().execute(sql, params)
  django/db/backends/utils.py", line 67, in execute
    return self._execute_with_wrappers(
  django/db/backends/utils.py", line 80, in _execute_with_wrappers
    return executor(sql, params, many, context)
  django/db/backends/utils.py", line 83, in _execute
    self.db.validate_no_broken_transaction()
  django/db/backends/base/base.py", line 531, in validate_no_broken_transaction
    raise TransactionManagementError(
django.db.transaction.TransactionManagementError: An error occurred in the current transaction. You can't execute queries until the end of the 'atomic' block.

I do not mind that this exceptioned, the problem is the stack trace it produced is leaking stuff between different call paths. In my case it was between unrelated celery tasks.

What's important to note here is the TransactionManagementError is from the fred function but the IntegrityError it shows as the cause is from the bob function. What we should be seeing instead is

django.core.exceptions.ValidationError: ['“bobit” value must be a decimal number.']

My understanding is that this validation error should have been captured into rollback_exc when needs_rollback was set to True
needs_rollback is getting set in Atomic.__exit__ when exc_type is set and connection.needs_rollback is False

Alternatively maybe there's some error handling missing in bulk_create. Although even if that's the case it seems bad that
Atomic.__exit__ can turn on needs_rollback without setting rollback_exc. Also perhaps rollback_exc should be getting cleared when needs_rollback is cleared.

I can't test this on 5.2 but Atomic.__exit__ looks unchanged.

Change History (2)

comment:1 by Gordon Wrigley, 5 months ago

Description: modified (diff)

comment:2 by Gordon Wrigley, 5 months ago

Description: modified (diff)
Summary: Bad stack trace during rollbackBad stack trace during rollback after bulk create
Note: See TracTickets for help on using tickets.
Back to Top