[Question] django ATOMIC_REQUESTS setting is not working

Chanmoro commented 1 year ago

Hello. I'm trying to django's ATOMIC_REQUESTS setting with django ninja, but seems does not work.

On the other hand, it works fine using django.db.transaction as decorator instead of setting.

@router.delete("/items/{item_id}")
@transaction.atomic
def delete_item(request: HttpRequest, item_id: int):
    ...

How can I use ATOMIC_REQUESTS with django ninja?

vitalik commented 1 year ago

@Chanmoro

django-ninja should not influence ATOMIC_REQUESTS behavour..

maybe you setting it in the wrong palce ? keep in mind that ATOMIC_REQUESTS is part of DATABASES section not a standalone section

Chanmoro commented 1 year ago

@vitalik Thank you very much for your reply.

I have tested some behavior ATOMIC_REQUESTS and transaction.atomic decorator. ATOMIC_REQUESTS setting still doesn't seem to work.

Reproduction code is in this repository. https://github.com/Chanmoro/django-ninja-619-reproduction

Could you confirm these result?

Setting

Django's database setting is as below.

DATABASES = {
    'default': {
        'ENGINE': "django.db.backends.postgresql",
        'HOST': os.getenv('DB_HOST'),
        'PORT': os.getenv('DB_PORT'),
        'USER': os.getenv('DB_USER'),
        'PASSWORD': os.getenv('DB_PASSWORD'),
        'NAME': os.getenv('DB_DATABASE'),
        'ATOMIC_REQUESTS': True,
    }
}

And output sql log on PostgreSQL using log_min_duration_statement setting.

case1: Test ATOMIC_REQUESTS

Transaction has started before insert, but it has not rollback after exception. It's not expected behavior.

API code

@api.post("/test_atomic_requests")
def test_atomic_requests(request):
Item.objects.create(name="test_atomic_requests")
raise Exception()

HTTP Request

$ curl -XPOST localhost:8000/api/test_atomic_requests

SQL log

2022-12-13 15:18:25.337 GMT [96] LOG:  duration: 0.254 ms  statement: SET TIME ZONE 'UTC'
2022-12-13 15:18:25.337 GMT [96] LOG:  duration: 0.019 ms  statement: BEGIN
2022-12-13 15:18:25.339 GMT [96] LOG:  duration: 0.804 ms  statement: INSERT INTO "app_item" ("name") VALUES ('test_atomic_requests') RETURNING "app_item"."id"
2022-12-13 15:18:25.341 GMT [96] LOG:  duration: 0.948 ms  statement: COMMIT

case2: Test transaction.atomic decorator (declared before routing)

Transaction has started before insert, and it has rollback after exception. It's expected behavior.

@api.post("/test_transaction_atomic_before")
@transaction.atomic
def test_transaction_atomic_before(request):
    Item.objects.create(name="test_transaction_atomic_before")
    raise Exception()

HTTP Request

$ curl -XPOST localhost:8000/api/test_atomic_requests

SQL log

2022-12-13 15:18:30.268 GMT [97] LOG:  duration: 0.301 ms  statement: SET TIME ZONE 'UTC'
2022-12-13 15:18:30.268 GMT [97] LOG:  duration: 0.016 ms  statement: BEGIN
2022-12-13 15:18:30.269 GMT [97] LOG:  duration: 0.052 ms  statement: SAVEPOINT "s140716743321344_x1"
2022-12-13 15:18:30.270 GMT [97] LOG:  duration: 0.671 ms  statement: INSERT INTO "app_item" ("name") VALUES ('test_transaction_atomic_before') RETURNING "app_item"."id"
2022-12-13 15:18:30.271 GMT [97] LOG:  duration: 0.031 ms  statement: ROLLBACK TO SAVEPOINT "s140716743321344_x1"
2022-12-13 15:18:30.271 GMT [97] LOG:  duration: 0.115 ms  statement: RELEASE SAVEPOINT "s140716743321344_x1"
2022-12-13 15:18:30.275 GMT [97] LOG:  duration: 2.861 ms  statement: COMMIT

case3: Test transaction.atomic decorator (declared after routing)

Transaction has started before insert, but it has not rollback after exception. It's not expected behavior.

API code

@transaction.atomic
@api.post("/test_transaction_atomic_after")
def test_transaction_atomic(request):
Item.objects.create(name="test_transaction_atomic_after")
raise Exception()

HTTP Request

$ curl -XPOST localhost:8000/api/test_atomic_requests

SQL log

2022-12-13 15:18:35.751 GMT [98] LOG:  duration: 0.262 ms  statement: SET TIME ZONE 'UTC'
2022-12-13 15:18:35.752 GMT [98] LOG:  duration: 0.016 ms  statement: BEGIN
2022-12-13 15:18:35.753 GMT [98] LOG:  duration: 0.670 ms  statement: INSERT INTO "app_item" ("name") VALUES ('test_transaction_atomic_after') RETURNING "app_item"."id"
2022-12-13 15:18:35.754 GMT [98] LOG:  duration: 0.667 ms  statement: COMMIT

Lunrtick commented 1 year ago

@Chanmoro Did you ever figure this out/was it ever fixed? I'm running into the same behaviour now on version 1.0b1. @vitalik I see this was closed before all this testing/repro was added. Was it fixed? If not, I'd be happy to help.

vitalik commented 1 year ago

Hi @Lunrtick

1) do you put atomic decorator before @api.get or after ? can you show. your code ?

2) did you make any custom error handler

3) does it behaves differently when you have DEBUG = True/False ?

Lunrtick commented 1 year ago

Thanks for taking a look @vitalik .

do you put atomic decorator before @api.get or after ? can you show. your code ?

My current setup is just using ATOMIC_REQUESTS, though I see @Chanmoro has tried it with the decorator both before and after routing. The problem seems solved when the @transaction.atomic runs first. This seems to indicate that an exception is being swallowed/handled inside the route registration decorator, but I guess I'll need to investigate that a bit deeper.

did you make any custom error handler

No, no custom error handlers.

does it behaves differently when you have DEBUG = True/False ?

I'll investigate this later today when I get a chance. I don't think it behaves differently as I noticed the problem both locally with DEBUG=True and in a staging env with DEBUG=False.

Lunrtick commented 1 year ago

It seems I was mistaken. The behaviour is different with DEBUG=False.

Specifically, the _default_exception function on line 104 of errors.py (https://github.com/vitalik/django-ninja/blob/e5e3a4c34afd136459dc00d6d2240604d3022bb5/ninja/errors.py#L104-L112).

As you would expect, the exception is only swallowed in DEBUG mode.

It seems that there isn't actually a problem here then, given that you should never be running DEBUG=True in production. Ideally I think this should be mentioned somewhere in the Docs - I'll make a PR for that when I get a chance (if you'd like).

Sorry about the mixup, and thanks for an awesome library @vitalik!

jlost commented 2 days ago

Breaking ATOMIC_REQUESTS when DEBUG=True doesn't seem like the right behavior.

vitalik / django-ninja