ask/django-celery — Issue #93: "ProgrammingError: closing a closed connection"
Author: domino14
Created: 2011-11-29 09:29:30+00:00
State: open

I get log messages like the following when a task is about to begin executing:

2011-11-27 10:52:10,626 DEBG 'myceleryd2' stderr output:
[2011-11-27 02:52:10,626: WARNING/PoolWorker-1] /usr/local/lib/python2.6/dist-packages/celery/worker/job.py:113: UserWarning: Exception outside body: : closing a closed connection
Traceback (most recent call last):
File "/usr/local/lib/python2.6/dist-packages/celery/worker/job.py", line 107, in execute_safe
return self.execute(*args, **kwargs)
File "/usr/local/lib/python2.6/dist-packages/celery/worker/job.py", line 118, in execute
self.loader.on_task_init(self.task_id, self.task)
File "/usr/local/lib/python2.6/dist-packages/djcelery/loaders.py", line 72, in on_task_init
self.close_database()
File "/usr/local/lib/python2.6/dist-packages/djcelery/loaders.py", line 47, in close_database
return django.db.close_connection()
File "/usr/local/lib/python2.6/dist-packages/django/db/__init__.py", line 84, in close_connection
conn.close()
File "/usr/local/lib/python2.6/dist-packages/django/db/backends/__init__.py", line 70, in close
self.connection.close()
ProgrammingError: closing a closed connection

map(str, (exc.__class__, exc, exc_info.traceback))))

or

2011-11-27 10:52:10,747 DEBG 'myceleryd2' stderr output:
[2011-11-27 02:52:10,731: ERROR/MainProcess] Task base.tasks.MyTask[76430fd4-1159-434a-a2bc-33af0828e94f] raised exception: ProgrammingError('closing a closed connection',)
Traceback (most recent call last):
File "/usr/local/lib/python2.6/dist-packages/celery/worker/job.py", line 107, in execute_safe
return self.execute(*args, **kwargs)
File "/usr/local/lib/python2.6/dist-packages/celery/worker/job.py", line 118, in execute
self.loader.on_task_init(self.task_id, self.task)
File "/usr/local/lib/python2.6/dist-packages/djcelery/loaders.py", line 72, in on_task_init
self.close_database()
File "/usr/local/lib/python2.6/dist-packages/djcelery/loaders.py", line 47, in close_database
return django.db.close_connection()
File "/usr/local/lib/python2.6/dist-packages/django/db/__init__.py", line 84, in close_connection
conn.close()
File "/usr/local/lib/python2.6/dist-packages/django/db/backends/__init__.py", line 70, in close
self.connection.close()
ProgrammingError: closing a closed connection
None

----

The celery process will run fine for a long time (several days) then suddenly once this error comes up it pops up all the time and my tasks start to not execute reliably anymore. One major hint I found happened immediately prior to the first error:

011-11-27 10:52:10,625 DEBG 'myceleryd2' stderr output:
[2011-11-27 02:52:10,507: ERROR/PoolWorker-1] Process cleanup failed: SoftTimeLimitExceeded()
Traceback (most recent call last):
File "/usr/local/lib/python2.6/dist-packages/celery/worker/job.py", line 129, in execute
self.loader.on_process_cleanup()
File "/usr/local/lib/python2.6/dist-packages/djcelery/loaders.py", line 67, in on_process_cleanup
self.close_database()
File "/usr/local/lib/python2.6/dist-packages/djcelery/loaders.py", line 47, in close_database
return django.db.close_connection()
File "/usr/local/lib/python2.6/dist-packages/django/db/__init__.py", line 84, in close_connection
conn.close()
File "/usr/local/lib/python2.6/dist-packages/django/db/backends/__init__.py", line 70, in close
self.connection.close()
File "/usr/local/lib/python2.6/dist-packages/celery/concurrency/processes/pool.py", line 114, in soft_timeout_sighandler
raise SoftTimeLimitExceeded()
SoftTimeLimitExceeded
[2011-11-27 02:52:10,624: INFO/MainProcess] Task base.tasks.AnotherTask[7742d1ef-9a75-477d-b0fe-b4d95a8859be] succeeded in 10.3231940269s: None

Of note is that this exception happened right after the task printed out its "done" message, in the 'run()' function of the Task subclass. So my aggressive soft time limit of 10 seconds was exceeded during the cleanup. Could this be what causes the connections to begin failing?