Possible race condition between Django post_save signal and celery task

Question

In a django 2.0 app I have a model, called Document, that uploads and saves an image to the file system. That part works. I am performing some facial recognition on the image using https://github.com/ageitgey/face_recognition in a celery (v 4.2.1) task. I pass the document_id of the image to the celery task so the face-recognition task can find the image to work on. This all works well if I call the face_recognition task manually from a DocumentAdmin action after the image is saved.

I tried calling the face_recognition task from a (models.signals.post_save, sender=Document) method in my models.py, and I get an error from this line in the celery task for face_recognition:

document = Document.objects.get(document_id=document_id)

and the error is:

[2018-11-26 16:54:28,594: ERROR/ForkPoolWorker-1] Task biometric_identification.tasks.find_faces_task[428ca39b-aefb-4174-9906-ff2146fd6f14] raised unexpected: DoesNotExist('Document matching query does not exist.',)
Traceback (most recent call last):
  File "/home/mark/.virtualenvs/memorabilia-JSON/lib/python3.6/site-packages/celery/app/trace.py", line 382, in trace_task
    R = retval = fun(*args, **kwargs)
  File "/home/mark/.virtualenvs/memorabilia-JSON/lib/python3.6/site-packages/celery/app/trace.py", line 641, in __protected_call__
    return self.run(*args, **kwargs)
  File "/home/mark/python-projects/memorabilia-JSON/biometric_identification/tasks.py", line 42, in find_faces_task
    document = Document.objects.get(document_id=document_id)
  File "/home/mark/.virtualenvs/memorabilia-JSON/lib/python3.6/site-packages/django/db/models/manager.py", line 82, in manager_method
    return getattr(self.get_queryset(), name)(*args, **kwargs)
  File "/home/mark/.virtualenvs/memorabilia-JSON/lib/python3.6/site-packages/django/db/models/query.py", line 403, in get
    self.model._meta.object_name
memorabilia.models.DoesNotExist: Document matching query does not exist.

Also, this error does not occur all the time, only occasionally. The rest of the time, the process works; ie the image is saved and the faces are identified.

I override save_model in the DocumentAdmin class, but that just saves some metadata for the image in another model. The last line is a call to super().save_model(request, obj, form, change), so I assume the post_save signal is called after that.

It appears to me that there is a race condition between saving the model to the database and the celery task querying the database for the newly created document_id. I thought the post_save signal wasn't activated until the model was saved?

Do I have to add some artificial delay in the celery task face_recognition in order to work around this possible race condition, or am I missing something else?

Thanks!

Mark

Answer 1

Check your function where Document model is saved. It is wrapped in atomic block somewhere or you have ATOMIC_REQUESTS set to True. So when post_save is called, the transaction is not committed yet. So your model is not really saved to the database at that moment of time.

Answer 2

It seems that sometimes the signal beats your db-write speed! What you can do as a harmful workaround is to run the celery task a bit later, just by a few seconds.

Here is how it's done:

your_task.apply_async(
            [document_id],
            countdown=5 # this is the delay in seconds - you can adapt it accordingly
        )

Let me know if that works for your case!

Answer 3

As mentioned in the @UnholyRaven's answer, the problem is connected to the transaction not being committed at the moment the task is executed.

To solve that, we can schedule the task on the transaction commit using Django's transaction.on_commit

@receiver(post_save, sender=Document):
find_faces(sender, instance, created, **kwargs):
  transaction.on_commit(lambda: find_faces_task.apply_async([instance.id]))