Error in timer: InterfaceError('connection already closed',)

[tijs]

I'm running celery worker, cam and beat using the django manage commands and i see the following error in my logs every minute:

django.db.backends in _rollback
Error in timer: InterfaceError('connection already closed',)

I've checked past issues, etc but the only reference to this error dates back to django-celery 2.5.0 while i'm running a recent

django-celery==3.0.23

installed through the django-celery-with-redis package.

i've tried turning off cam and beat but the issue remains so it seems to be specific to celery worker. this is an ubuntu system running postgres 9.1 with the latest psycopg2==2.5.1

Anything i could try to get rid of this error? After a while it results in hanging/idle connections in postgres so just silencing it will not be enough as it would make my database server unresponsive if i leave it running long enough.

Stacktrace (most recent call last):

  File "celery/utils/timer2.py", line 109, in apply_entry
    entry()
  File "celery/utils/timer2.py", line 59, in __call__
    return self.fun(*self.args, **self.kwargs)
  File "celery/utils/timer2.py", line 165, in _reschedules
    return fun(*args, **kwargs)
  File "celery/events/snapshot.py", line 71, in capture
    self.state.freeze_while(self.shutter, clear_after=self.clear_after)
  File "celery/events/state.py", line 232, in freeze_while
    return fun(*args, **kwargs)
  File "celery/events/snapshot.py", line 68, in shutter
    self.on_shutter(self.state)
  File "django/db/transaction.py", line 223, in inner
    return func(*args, **kwargs)
  File "django/db/transaction.py", line 217, in __exit__
    self.exiting(exc_value, self.using)
  File "django/db/transaction.py", line 302, in exiting
    leave_transaction_management(using=using)
  File "django/db/transaction.py", line 66, in leave_transaction_management
    connection.leave_transaction_management()
  File "django/db/backends/__init__.py", line 136, in leave_transaction_management
    self.rollback()
  File "django/db/backends/__init__.py", line 249, in rollback
    self._rollback()
  File "django/db/backends/__init__.py", line 59, in _rollback
    return self.connection.rollback()

[tijs]

I tried downgrading all the way back to celery 3.0.17 in one version incremenst but that did not seem to help so i gave that up. Could any other package influence this perhaps?

[adriaant]

Are you use multiprocessing? If you spawn a multiprocessing process, you'd get this error if you didn't explicitly close a db connection.

[tijs]

I have multiple workers setup (--autoscale=6,2) but none of them do anything more fancy than send an email or change some value in the database. All discrete actions. If the task calls other tasks it's always without returning results.

[tijs]

@adriaant could the cause be that i'm passing an object instead of the object's id (and then reatrieving teh object in the task itself) in one or two of the tasks?

[adriaant]

The one time I ran into this issue was because django is using the same database connection for all processes. Normally, when you have concurrent db requests, they are either in the same thread (in which case GIL kicks in) or they are on separate threads, in which case django makes different database connections. But with multiprocessing, python makes deep copies of everything, so it's passing the same database connection to the subprocesses, and then they step on each other until it breaks. Solution is to trigger a new db connection.

But then again, not sure if that's the issue in your case :)

[tijs]

@adriaant i'm not doing anything fancy so i would be surprised if i'm running into that. But i will refactor the remaining tasks that pass around querysets just to be sure that's not it. I'll report back here if that turns out to be the issue.

[adriaant]

If you pass around querysets, that could indeed be the issue. Django doesn't make a db connection until you actually get something out of a queryset. You could cast the queryset to a list, so that Django retrieves the data, and then pass that list around.

[tijs]

I've fixed passing around querysets but that was not the issue. Seems either having --autoreload or --events on was causing the issue. I should not have turned both off of course so i'll try to find which of those settings was casuing this by turning them one one by one on staging after i fix some other things.

[ask]

This error often masks a different error that happened earlier, so check your database logs.

Multiprocessing absolutely does not deepcopy anything, instead it's simply a side effect of the unix process model,
where the fork system call creates a new process inheriting the memory of the parent process (including file descriptors).
Django-celery will automatically close the connections after fork, so I think it's more likely that this is a different problem, e.g. an error occurred and the connection was automatically closed, celery or something else then tries to close the connection again but the PostgreSQL interface does not allow you to close the connection twice.

[adriaant]

Thanks for the correction on deep copy. It is indeed just a copy of the memory space.

[tijs]

I can't reproduce it anymore so i'll write it up to an unfortunate combination of settings and close this one.