ask/celery — Issue #609: MySQL error in storing task results shuts down Celery
Author: lsemel
Created: 2012-02-14 15:21:24+00:00
State: open

I am using the MySQL backend, and last night it encountered an error in storing task results, the "Lock wait timeout exceeded" error. Instead of just continuing, this looks like it caused Celery to shut down completely.

[2012-02-14 05:01:38,434: INFO/PoolWorker-1] child process calling self.run()
[2012-02-14 05:01:38,443: INFO/PoolWorker-2] child process calling self.run()
[2012-02-14 05:01:38,452: INFO/PoolWorker-3] child process calling self.run()
[2012-02-14 05:01:38,460: INFO/PoolWorker-4] child process calling self.run()
[2012-02-14 05:01:38,470: INFO/PoolWorker-5] child process calling self.run()
[2012-02-14 05:01:38,479: INFO/PoolWorker-6] child process calling self.run()
[2012-02-14 05:01:38,487: INFO/PoolWorker-7] child process calling self.run()
[2012-02-14 05:01:38,495: INFO/PoolWorker-8] child process calling self.run()
[2012-02-14 05:01:38,503: INFO/PoolWorker-9] child process calling self.run()
[2012-02-14 05:01:38,513: INFO/PoolWorker-10] child process calling self.run()
[2012-02-14 05:01:38,522: INFO/PoolWorker-11] child process calling self.run()
[2012-02-14 05:01:38,530: INFO/PoolWorker-12] child process calling self.run()
[2012-02-14 05:01:38,549: INFO/MainProcess] Got task from broker: explore.tasks.update_trending_terms[48716e92-acbe-4389-b6cc-b674a991f576]
[2012-02-14 05:04:13,616: ERROR/MainProcess] Unrecoverable error: OperationalError(1205, 'Lock wait timeout exceeded; try restarting transaction')
Traceback (most recent call last):
File "/opt/virtualenvs/muckrack/src/celery/celery/worker/__init__.py", line 230, in start
component.start()
File "/opt/virtualenvs/muckrack/src/celery/celery/worker/consumer.py", line 339, in start
self.consume_messages()
File "/opt/virtualenvs/muckrack/src/celery/celery/worker/consumer.py", line 355, in consume_messages
self.connection.drain_events(timeout=1)
File "/opt/virtualenvs/muckrack/src/kombu/kombu/connection.py", line 195, in drain_events
return self.transport.drain_events(self.connection, **kwargs)
File "/opt/virtualenvs/muckrack/src/kombu/kombu/transport/amqplib.py", line 235, in drain_events
return connection.drain_events(**kwargs)
File "/opt/virtualenvs/muckrack/src/kombu/kombu/transport/amqplib.py", line 67, in drain_events
return self.wait_multi(self.channels.values(), timeout=timeout)
File "/opt/virtualenvs/muckrack/src/kombu/kombu/transport/amqplib.py", line 94, in wait_multi
return amqp_method(channel, args, content)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/amqplib/client_0_8/channel.py", line 2060, in _basic_deliver
func(msg)
File "/opt/virtualenvs/muckrack/src/kombu/kombu/messaging.py", line 477, in _receive_callback
self.receive(decoded, message)
File "/opt/virtualenvs/muckrack/src/kombu/kombu/messaging.py", line 443, in receive
[callback(body, message) for callback in callbacks]
File "/opt/virtualenvs/muckrack/src/celery/celery/worker/consumer.py", line 444, in receive_message
self.strategies[name](message, body, message.ack_log_error)
File "/opt/virtualenvs/muckrack/src/celery/celery/worker/strategy.py", line 19, in task_message_handler
task=task))
File "/opt/virtualenvs/muckrack/src/celery/celery/worker/consumer.py", line 370, in on_task
if task.revoked():
File "/opt/virtualenvs/muckrack/src/celery/celery/worker/job.py", line 258, in revoked
self.maybe_expire()
File "/opt/virtualenvs/muckrack/src/celery/celery/worker/job.py", line 245, in maybe_expire
self.task.backend.mark_as_revoked(self.id)
File "/opt/virtualenvs/muckrack/src/celery/celery/backends/base.py", line 106, in mark_as_revoked
status=states.REVOKED, traceback=None)
File "/opt/virtualenvs/muckrack/src/celery/celery/backends/base.py", line 229, in store_result
return self._store_result(task_id, result, status, traceback, **kwargs)
File "/opt/virtualenvs/muckrack/src/django-celery/djcelery/backends/database.py", line 27, in _store_result
traceback=traceback)
File "/opt/virtualenvs/muckrack/src/django-celery/djcelery/managers.py", line 41, in _inner
return fun(*args, **kwargs)
File "/opt/virtualenvs/muckrack/src/django-celery/djcelery/managers.py", line 169, in store_result
"traceback": traceback})
File "/opt/virtualenvs/muckrack/src/django-celery/djcelery/managers.py", line 83, in update_or_create
return self.get_query_set().update_or_create(**kwargs)
File "/opt/virtualenvs/muckrack/src/django-celery/djcelery/managers.py", line 67, in update_or_create
obj, created = self.get_or_create(**kwargs)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/query.py", line 385, in get_or_create
obj.save(force_insert=True, using=self.db)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/base.py", line 460, in save
self.save_base(using=using, force_insert=force_insert, force_update=force_update)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/base.py", line 553, in save_base
result = manager._insert(values, return_id=update_pk, using=using)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/manager.py", line 195, in _insert
return insert_query(self.model, values, **kwargs)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/query.py", line 1436, in insert_query
return query.get_compiler(using=using).execute_sql(return_id)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/sql/compiler.py", line 791, in execute_sql
cursor = super(SQLInsertCompiler, self).execute_sql(None)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/sql/compiler.py", line 735, in execute_sql
cursor.execute(sql, params)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/backends/mysql/base.py", line 86, in execute
return self.cursor.execute(query, args)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/newrelic-1.1.0.192/newrelic/hooks/database_dbapi2.py", line 32, in execute
return self._nr_cursor.execute(sql, *args, **kwargs)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/MySQLdb/cursors.py", line 174, in execute
self.errorhandler(self, exc, value)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
raise errorclass, errorvalue
OperationalError: (1205, 'Lock wait timeout exceeded; try restarting transaction')
[2012-02-14 05:04:13,623: ERROR/MainProcess] Task explore.tasks.update_trending_terms[48716e92-acbe-4389-b6cc-b674a991f576] raised exception: OperationalError(1205, 'Lock wait timeout
exceeded; try restarting transaction')
Traceback (most recent call last):
File "/opt/virtualenvs/muckrack/src/celery/celery/execute/trace.py", line 146, in trace_task
"hostname": hostname}, STARTED)
File "/opt/virtualenvs/muckrack/src/celery/celery/backends/base.py", line 229, in store_result
return self._store_result(task_id, result, status, traceback, **kwargs)
File "/opt/virtualenvs/muckrack/src/django-celery/djcelery/backends/database.py", line 27, in _store_result
traceback=traceback)
File "/opt/virtualenvs/muckrack/src/django-celery/djcelery/managers.py", line 41, in _inner
return fun(*args, **kwargs)
File "/opt/virtualenvs/muckrack/src/django-celery/djcelery/managers.py", line 169, in store_result
"traceback": traceback})
File "/opt/virtualenvs/muckrack/src/django-celery/djcelery/managers.py", line 83, in update_or_create
return self.get_query_set().update_or_create(**kwargs)
File "/opt/virtualenvs/muckrack/src/django-celery/djcelery/managers.py", line 67, in update_or_create
obj, created = self.get_or_create(**kwargs)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/query.py", line 385, in get_or_create
obj.save(force_insert=True, using=self.db)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/base.py", line 460, in save
self.save_base(using=using, force_insert=force_insert, force_update=force_update)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/base.py", line 553, in save_base
result = manager._insert(values, return_id=update_pk, using=using)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/manager.py", line 195, in _insert
return insert_query(self.model, values, **kwargs)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/query.py", line 1436, in insert_query
return query.get_compiler(using=using).execute_sql(return_id)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/sql/compiler.py", line 791, in execute_sql
cursor = super(SQLInsertCompiler, self).execute_sql(None)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/sql/compiler.py", line 735, in execute_sql
cursor.execute(sql, params)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/backends/mysql/base.py", line 86, in execute
return self.cursor.execute(query, args)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/newrelic-1.1.0.192/newrelic/hooks/database_dbapi2.py", line 32, in execute
return self._nr_cursor.execute(sql, *args, **kwargs)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/MySQLdb/cursors.py", line 174, in execute
self.errorhandler(self, exc, value)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
raise errorclass, errorvalue
OperationalError: (1205, 'Lock wait timeout exceeded; try restarting transaction')
Traceback (most recent call last):
File "/opt/virtualenvs/muckrack/src/celery/celery/execute/trace.py", line 146, in trace_task
"hostname": hostname}, STARTED)
File "/opt/virtualenvs/muckrack/src/celery/celery/backends/base.py", line 229, in store_result
return self._store_result(task_id, result, status, traceback, **kwargs)
File "/opt/virtualenvs/muckrack/src/django-celery/djcelery/backends/database.py", line 27, in _store_result
traceback=traceback)
File "/opt/virtualenvs/muckrack/src/django-celery/djcelery/managers.py", line 41, in _inner
return fun(*args, **kwargs)
File "/opt/virtualenvs/muckrack/src/django-celery/djcelery/managers.py", line 169, in store_result
"traceback": traceback})
File "/opt/virtualenvs/muckrack/src/django-celery/djcelery/managers.py", line 83, in update_or_create
return self.get_query_set().update_or_create(**kwargs)
File "/opt/virtualenvs/muckrack/src/django-celery/djcelery/managers.py", line 67, in update_or_create
obj, created = self.get_or_create(**kwargs)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/query.py", line 385, in get_or_create
obj.save(force_insert=True, using=self.db)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/base.py", line 460, in save
self.save_base(using=using, force_insert=force_insert, force_update=force_update)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/base.py", line 553, in save_base
result = manager._insert(values, return_id=update_pk, using=using)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/manager.py", line 195, in _insert
return insert_query(self.model, values, **kwargs)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/query.py", line 1436, in insert_query
return query.get_compiler(using=using).execute_sql(return_id)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/sql/compiler.py", line 791, in execute_sql
cursor = super(SQLInsertCompiler, self).execute_sql(None)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/models/sql/compiler.py", line 735, in execute_sql
cursor.execute(sql, params)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/django/db/backends/mysql/base.py", line 86, in execute
return self.cursor.execute(query, args)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/newrelic-1.1.0.192/newrelic/hooks/database_dbapi2.py", line 32, in execute
return self._nr_cursor.execute(sql, *args, **kwargs)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/MySQLdb/cursors.py", line 174, in execute
self.errorhandler(self, exc, value)
File "/opt/virtualenvs/muckrack/lib/python2.6/site-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
raise errorclass, errorvalue
OperationalError: (1205, 'Lock wait timeout exceeded; try restarting transaction')
[2012-02-14 05:04:13,916: INFO/PoolWorker-11] process shutting down
[2012-02-14 05:04:13,916: INFO/PoolWorker-7] process shutting down
[2012-02-14 05:04:13,917: INFO/PoolWorker-7] process exiting with exitcode 0
[2012-02-14 05:04:13,917: INFO/PoolWorker-11] process exiting with exitcode 0
[2012-02-14 05:04:13,917: INFO/PoolWorker-9] process shutting down
[2012-02-14 05:04:13,917: INFO/PoolWorker-9] process exiting with exitcode 0
[2012-02-14 05:04:13,919: INFO/PoolWorker-6] process shutting down
[2012-02-14 05:04:13,919: INFO/PoolWorker-6] process exiting with exitcode 0
[2012-02-14 05:04:13,921: INFO/PoolWorker-2] process shutting down
[2012-02-14 05:04:13,921: INFO/PoolWorker-2] process exiting with exitcode 0
[2012-02-14 05:04:13,921: INFO/PoolWorker-4] process shutting down
[2012-02-14 05:04:13,922: INFO/PoolWorker-4] process exiting with exitcode 0
[2012-02-14 05:04:13,923: INFO/PoolWorker-12] process shutting down
[2012-02-14 05:04:13,923: INFO/PoolWorker-12] process exiting with exitcode 0
[2012-02-14 05:04:13,923: INFO/PoolWorker-3] process shutting down
[2012-02-14 05:04:13,924: INFO/PoolWorker-3] process exiting with exitcode 0
[2012-02-14 05:04:13,925: INFO/PoolWorker-8] process shutting down
[2012-02-14 05:04:13,925: INFO/PoolWorker-8] process exiting with exitcode 0
[2012-02-14 05:04:13,926: INFO/PoolWorker-1] process shutting down
[2012-02-14 05:04:13,926: INFO/PoolWorker-1] process exiting with exitcode 0
[2012-02-14 05:04:13,926: INFO/PoolWorker-10] process shutting down
[2012-02-14 05:04:13,926: INFO/PoolWorker-10] process exiting with exitcode 0
[2012-02-14 05:04:13,927: INFO/PoolWorker-5] process shutting down
[2012-02-14 05:04:13,927: INFO/PoolWorker-5] process exiting with exitcode 0
[2012-02-14 05:04:13,936: INFO/MainProcess] process shutting down