Database locks should be handled

[jamescasbon]

If the database is locked, I get a nasty stacktrace (see below). I think kombu should sleep and retry until there is not a lock

I think this is because a large write from the previous task happening (with a test sqlite db)

(workflow)james@flapjack:~/Documents/pgt-work/repo/adhoc/ucsc_test$ celeryd --concurrency 1
[2011-04-17 18:33:40,020: WARNING/MainProcess]

-------------- celery@flapjack.local v2.2.6
---- **** -----
--- * *** * -- [Configuration]
-- * - **** --- . broker: sqlakombu.transport.Transport://guest@sqlite:///primerdb.sqlite0/

• ** ---------- . loader: celery.loaders.default.Loader
• ** ---------- . logfile: [stderr]@warning
• ** ---------- . concurrency: 1
• ** ---------- . events: OFF
• *** --- * --- . beat: OFF
  -- ******* ----
  --- ***** ----- [Queues]
  -------------- . celery: exchange:celery (direct) binding:celery

[2011-04-17 18:33:40,036: WARNING/MainProcess] celery@flapjack.local has started.
...
[2011-04-17 18:38:25,642: WARNING/MainProcess] Traceback (most recent call last):
[2011-04-17 18:38:25,643: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/bin/celeryd", line 8, in
[2011-04-17 18:38:25,643: WARNING/MainProcess] load_entry_point('celery==2.2.6', 'console_scripts', 'celeryd')()
[2011-04-17 18:38:25,643: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/celery/bin/celeryd.py", line 187, in main
[2011-04-17 18:38:25,643: WARNING/MainProcess] worker.execute_from_commandline()
[2011-04-17 18:38:25,644: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/celery/bin/base.py", line 72, in execute_from_commandline
[2011-04-17 18:38:25,644: WARNING/MainProcess] return self.handle_argv(prog_name, argv[1:])
[2011-04-17 18:38:25,644: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/celery/bin/base.py", line 100, in handle_argv
[2011-04-17 18:38:25,645: WARNING/MainProcess] return self.run(_args, _vars(options))
[2011-04-17 18:38:25,645: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/celery/bin/celeryd.py", line 96, in run
[2011-04-17 18:38:25,645: WARNING/MainProcess] return self.app.Worker(_kwargs).run()
[2011-04-17 18:38:25,645: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/celery/apps/worker.py", line 135, in run
[2011-04-17 18:38:25,646: WARNING/MainProcess] self.run_worker()
[2011-04-17 18:38:25,646: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/celery/apps/worker.py", line 235, in run_worker
[2011-04-17 18:38:25,647: WARNING/MainProcess] worker.start()
[2011-04-17 18:38:25,647: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/celery/worker/init.py", line 250, in start
[2011-04-17 18:38:25,647: WARNING/MainProcess] blocking(component.start)
[2011-04-17 18:38:25,648: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/kombu/syn.py", line 14, in blocking
[2011-04-17 18:38:25,648: WARNING/MainProcess] return __sync_current(fun, *args, *_kwargs)
[2011-04-17 18:38:25,649: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/kombu/syn.py", line 30, in blocking
[2011-04-17 18:38:25,649: WARNING/MainProcess] return fun(_args, *_kwargs)
[2011-04-17 18:38:25,649: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/celery/worker/consumer.py", line 275, in start
[2011-04-17 18:38:25,649: WARNING/MainProcess] self.consume_messages()
[2011-04-17 18:38:25,650: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/celery/worker/consumer.py", line 291, in consume_messages
[2011-04-17 18:38:25,650: WARNING/MainProcess] self.connection.drain_events(timeout=1)
[2011-04-17 18:38:25,650: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/kombu/connection.py", line 139, in drain_events
[2011-04-17 18:38:25,651: WARNING/MainProcess] return self.transport.drain_events(self.connection, *_kwargs)
[2011-04-17 18:38:25,651: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/kombu/transport/virtual/init.py", line 646, in drain_events
[2011-04-17 18:38:25,651: WARNING/MainProcess] item, channel = self.cycle.get(timeout=timeout)
[2011-04-17 18:38:25,652: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/kombu/transport/virtual/scheduling.py", line 40, in get
[2011-04-17 18:38:25,652: WARNING/MainProcess] return self.fun(resource, *_kwargs), resource
[2011-04-17 18:38:25,652: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/kombu/transport/virtual/init.py", line 665, in _drain_channel
[2011-04-17 18:38:25,653: WARNING/MainProcess] return channel.drain_events(timeout=timeout)
[2011-04-17 18:38:25,653: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/kombu/transport/virtual/init.py", line 486, in drain_events
[2011-04-17 18:38:25,653: WARNING/MainProcess] return self._poll(self.cycle, timeout=timeout)
[2011-04-17 18:38:25,654: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/kombu/transport/virtual/init.py", line 259, in _poll
[2011-04-17 18:38:25,654: WARNING/MainProcess] return cycle.get()
[2011-04-17 18:38:25,654: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/kombu/transport/virtual/scheduling.py", line 40, in get
[2011-04-17 18:38:25,654: WARNING/MainProcess] return self.fun(resource, **kwargs), resource
[2011-04-17 18:38:25,658: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/sqlakombu/transport.py", line 64, in _get
[2011-04-17 18:38:25,658: WARNING/MainProcess] obj = self._get_or_create(queue)
[2011-04-17 18:38:25,659: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/sqlakombu/transport.py", line 40, in _get_or_create
[2011-04-17 18:38:25,659: WARNING/MainProcess] obj = self.session.query(Queue).filter(Queue.name == queue)
[2011-04-17 18:38:25,659: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 1630, in first
[2011-04-17 18:38:25,660: WARNING/MainProcess] ret = list(self[0:1])
[2011-04-17 18:38:25,660: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 1538, in getitem
[2011-04-17 18:38:25,661: WARNING/MainProcess] return list(res)
[2011-04-17 18:38:25,661: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 1699, in iter
[2011-04-17 18:38:25,662: WARNING/MainProcess] return self._execute_and_instances(context)
[2011-04-17 18:38:25,662: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 1704, in _execute_and_instances
[2011-04-17 18:38:25,663: WARNING/MainProcess] mapper=self._mapper_zero_or_none())
[2011-04-17 18:38:25,663: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 724, in execute
[2011-04-17 18:38:25,663: WARNING/MainProcess] clause, params or {})
[2011-04-17 18:38:25,664: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1191, in execute
[2011-04-17 18:38:25,664: WARNING/MainProcess] params)
[2011-04-17 18:38:25,664: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1271, in _execute_clauseelement
[2011-04-17 18:38:25,665: WARNING/MainProcess] return self.__execute_context(context)
[2011-04-17 18:38:25,665: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1302, in __execute_context
[2011-04-17 18:38:25,666: WARNING/MainProcess] context.parameters[0], context=context)
[2011-04-17 18:38:25,666: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1401, in _cursor_execute
[2011-04-17 18:38:25,667: WARNING/MainProcess] context)
[2011-04-17 18:38:25,667: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1394, in _cursor_execute
[2011-04-17 18:38:25,667: WARNING/MainProcess] context)
[2011-04-17 18:38:25,668: WARNING/MainProcess] File "/Users/james/Documents/virtualenvs/workflow/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 299, in do_execute
[2011-04-17 18:38:25,668: WARNING/MainProcess] cursor.execute(statement, parameters)
[2011-04-17 18:38:25,668: WARNING/MainProcess] sqlalchemy.exc
[2011-04-17 18:38:25,669: WARNING/MainProcess] .
[2011-04-17 18:38:25,669: WARNING/MainProcess] OperationalError
[2011-04-17 18:38:25,669: WARNING/MainProcess] :
2011-04-17 18:38:25,669: WARNING/MainProcess database is locked u'SELECT kombu_queue.id AS kombu_queue_id, kombu_queue.name AS kombu_queue_name \nFROM kombu_queue \nWHERE kombu_queue.name = ? \n LIMIT 1 OFFSET 0' ('celery',)

[jamescasbon]

bloody markdown!

[ask]

On Sunday, April 17, 2011 at 7:51 PM, jamescasbon wrote:
If the database is locked, I get a nasty stacktrace (see below). I think kombu should sleep and retry until there is not a lock

I think this is because a large write from the previous task happening (with a test sqlite db)

2011-04-17 18:38:25,669: WARNING/MainProcess database is locked u'SELECT kombu_queue.id AS kombu_queue_id, kombu_queue.name AS kombu_queue_name \nFROM kombu_queue \nWHERE kombu_queue.name = ? \n LIMIT 1 OFFSET 0' ('celery',)

Hmm. But how do we know that the database is locked? There is only an OperationalError it seems,
is this error raised consistently by every database backend?

This doesn't happen in django for some weird reason, maybe sqlite is configured differently in Django.

[jamescasbon]

If I understand correctly, this is kombu trying to get stuff from the message queue. If the queue is unavailable for a while, shouldn't it retry.

Maybe you can spec the max number of retries or something. It's probably because I am commiting a large amount of data in a worker, so the DB hasn't unlocked (I think).

[ask]

Yeah, I know but my question is more about the OperationalError exception, does this error always signify an intermittent error so we can ignore it and retry later, or could it be raised for exceptional cases as well, where we would like to crash the program?

[jamescasbon]

I see what you mean. Here's the sqlalchemy response:
http://groups.google.com/group/sqlalchemy/browse_thread/thread/6ae1b8d7a841b452

[ksamuel]

One should have at least the option to retry, and even a counter for the number of retry. I'm currently accessing the sqlite DB from several daemons, and it sucks when it locks and crash while it count just wait for 50ms to retry.

[andresriancho]

Confirming I still get this today with celery (3.1.6) , kombu (3.0.16) , SQLAlchemy (0.8.1)