DatabaseError between Oracle and Django with Celery

Question

I'm having trouble with what seems to be the very last step in the deployment of a Django-Celery-RabbitMQ project.

After running the celery, httpd and rabbitmq-server services through systemd, when I trigger a task in Django I see the message Received task: smartalec.tasks.match_loadfile_task

Where smartalec is my app, and match_loadfile_task is my task, the project is called tcida_api.

But after 30 seconds or so, there's a huge stacktrace which starts as follows (full debug log with exception below).

[2016-09-09 15:34:20,040: ERROR/MainProcess] Task smartalec.tasks.match_loadfile_task[740dc792-7410-4418-aa44-dd9c56b63b04] raised unexpected: DatabaseError(' <cx_Oracle._Error object at 0x3a3ed50>',)

Googling for "Django Oracle Celery DatabaseError" gets some queries about sharing threads on a single connection, but I'm not sure if that applies to me as I have "threaded=TRUE" in my Database config in project.settings.

I get the same when I run celery from the command line.

sudo /opt/tcida/virtualenv/smartalec/bin/celery -A my_django_project worker -l info

I don't have django celery installed, Django can make database queries no problem, through the shell and webpages, the configuration works on my local machine using django's developement server.

What can cause, or solve, this exception?

Full Celery DEBUG log, uncluding full stacktrace.

[amartin@ip-10-50-7-148 tcida_api]$ sudo /opt/tcida/virtualenv/smartalec/bin/celery -A tcida_api worker --concurrency 1 -l debug
/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/celery/platforms.py:812: RuntimeWarning: You are running the worker with superuser privileges, which is absolutely not recommended!

Please specify a different user using the -u option.

User information: uid=0 euid=0 gid=0 egid=0

  uid=uid, euid=euid, gid=gid, egid=egid,
[2016-09-09 16:14:22,995: DEBUG/MainProcess] | Worker: Preparing bootsteps.
[2016-09-09 16:14:22,997: DEBUG/MainProcess] | Worker: Building graph...
[2016-09-09 16:14:22,997: DEBUG/MainProcess] | Worker: New boot order: {Timer, Hub, Queues (intra), Pool, Autoscaler, StateDB, Autoreloader, Beat, Consumer}
[2016-09-09 16:14:22,999: DEBUG/MainProcess] | Consumer: Preparing bootsteps.
[2016-09-09 16:14:23,000: DEBUG/MainProcess] | Consumer: Building graph...
[2016-09-09 16:14:23,003: DEBUG/MainProcess] | Consumer: New boot order: {Connection, Events, Mingle, Tasks, Control, Agent, Gossip, Heart, event loop}

 -------------- celery@ip-10-50-7-148.eu-west-1.compute.internal v3.1.23 (Cipater)
---- **** ----- 
--- * ***  * -- Linux-3.10.0-229.11.1.el7.x86_64-x86_64-with-redhat-7.1-Maipo
-- * - **** --- 
- ** ---------- [config]
- ** ---------- .> app:         tcida_api:0x1a91850
- ** ---------- .> transport:   amqp://guest:**@localhost:5672//
- ** ---------- .> results:     disabled://
- *** --- * --- .> concurrency: 1 (prefork)
-- ******* ---- 
--- ***** ----- [queues]
 -------------- .> celery           exchange=celery(direct) key=celery


[tasks]
  . celery.backend_cleanup
  . celery.chain
  . celery.chord
  . celery.chord_unlock
  . celery.chunks
  . celery.group
  . celery.map
  . celery.starmap
  . smartalec.tasks.match_loadfile_task

[2016-09-09 16:14:23,005: DEBUG/MainProcess] | Worker: Starting Hub
[2016-09-09 16:14:23,005: DEBUG/MainProcess] ^-- substep ok
[2016-09-09 16:14:23,005: DEBUG/MainProcess] | Worker: Starting Pool
[2016-09-09 16:14:23,029: DEBUG/MainProcess] ^-- substep ok
[2016-09-09 16:14:23,030: DEBUG/MainProcess] | Worker: Starting Consumer
[2016-09-09 16:14:23,030: DEBUG/MainProcess] | Consumer: Starting Connection
[2016-09-09 16:14:23,038: DEBUG/MainProcess] Start from server, version: 0.9, properties: {u'information': u'Licensed under the MPL.  See http://www.rabbitmq.com/', u'product': u'RabbitMQ', u'copyright': u'Copyright (C) 2007-2013 GoPivotal, Inc.', u'capabilities': {u'exchange_exchange_bindings': True, u'consumer_cancel_notify': True, u'publisher_confirms': True, u'basic.nack': True}, u'platform': u'Erlang/OTP', u'version': u'3.1.5'}, mechanisms: [u'PLAIN', u'AMQPLAIN'], locales: [u'en_US']
[2016-09-09 16:14:23,039: DEBUG/MainProcess] Open OK!
[2016-09-09 16:14:23,039: INFO/MainProcess] Connected to amqp://guest:**@127.0.0.1:5672//
[2016-09-09 16:14:23,040: DEBUG/MainProcess] ^-- substep ok
[2016-09-09 16:14:23,040: DEBUG/MainProcess] | Consumer: Starting Events
[2016-09-09 16:14:23,047: DEBUG/MainProcess] Start from server, version: 0.9, properties: {u'information': u'Licensed under the MPL.  See http://www.rabbitmq.com/', u'product': u'RabbitMQ', u'copyright': u'Copyright (C) 2007-2013 GoPivotal, Inc.', u'capabilities': {u'exchange_exchange_bindings': True, u'consumer_cancel_notify': True, u'publisher_confirms': True, u'basic.nack': True}, u'platform': u'Erlang/OTP', u'version': u'3.1.5'}, mechanisms: [u'PLAIN', u'AMQPLAIN'], locales: [u'en_US']
[2016-09-09 16:14:23,047: DEBUG/MainProcess] Open OK!
[2016-09-09 16:14:23,048: DEBUG/MainProcess] using channel_id: 1
[2016-09-09 16:14:23,048: DEBUG/MainProcess] Channel open
[2016-09-09 16:14:23,049: DEBUG/MainProcess] ^-- substep ok
[2016-09-09 16:14:23,049: DEBUG/MainProcess] | Consumer: Starting Mingle
[2016-09-09 16:14:23,049: INFO/MainProcess] mingle: searching for neighbors
[2016-09-09 16:14:23,050: DEBUG/MainProcess] using channel_id: 1
[2016-09-09 16:14:23,050: DEBUG/MainProcess] Channel open
[2016-09-09 16:14:24,056: INFO/MainProcess] mingle: all alone
[2016-09-09 16:14:24,057: DEBUG/MainProcess] ^-- substep ok
[2016-09-09 16:14:24,057: DEBUG/MainProcess] | Consumer: Starting Tasks
[2016-09-09 16:14:24,059: DEBUG/MainProcess] ^-- substep ok
[2016-09-09 16:14:24,059: DEBUG/MainProcess] | Consumer: Starting Control
[2016-09-09 16:14:24,059: DEBUG/MainProcess] using channel_id: 2
[2016-09-09 16:14:24,060: DEBUG/MainProcess] Channel open
[2016-09-09 16:14:24,062: DEBUG/MainProcess] ^-- substep ok
[2016-09-09 16:14:24,062: DEBUG/MainProcess] | Consumer: Starting Gossip
[2016-09-09 16:14:24,062: DEBUG/MainProcess] using channel_id: 3
[2016-09-09 16:14:24,063: DEBUG/MainProcess] Channel open
[2016-09-09 16:14:24,065: DEBUG/MainProcess] ^-- substep ok
[2016-09-09 16:14:24,065: DEBUG/MainProcess] | Consumer: Starting Heart
[2016-09-09 16:14:24,066: DEBUG/MainProcess] ^-- substep ok
[2016-09-09 16:14:24,066: DEBUG/MainProcess] | Consumer: Starting event loop
[2016-09-09 16:14:24,067: WARNING/MainProcess] celery@ip-10-50-7-148.eu-west-1.compute.internal ready.
[2016-09-09 16:14:24,067: DEBUG/MainProcess] | Worker: Hub.register Pool...
[2016-09-09 16:14:24,067: DEBUG/MainProcess] basic.qos: prefetch_count->4
[2016-09-09 16:14:31,300: INFO/MainProcess] Received task: smartalec.tasks.match_loadfile_task[51fed74e-f0ce-4cad-9a3d-283b830939d6]
[2016-09-09 16:14:31,300: DEBUG/MainProcess] TaskPool: Apply <function _fast_trace_task at 0x1c50500> (args:(u'smartalec.tasks.match_loadfile_task', u'51fed74e-f0ce-4cad-9a3d-283b830939d6', [1], {}, {u'utc': True, u'is_eager': False, u'chord': None, u'group': None, u'args': [1], u'retries': 0, u'delivery_info': {u'priority': 0, u'redelivered': False, u'routing_key': u'celery', u'exchange': u'celery'}, u'expires': None, u'hostname': 'celery@ip-10-50-7-148.eu-west-1.compute.internal', u'task': u'smartalec.tasks.match_loadfile_task', u'callbacks': None, u'correlation_id': u'51fed74e-f0ce-4cad-9a3d-283b830939d6', u'errbacks': None, u'timelimit': [None, None], u'taskset': None, u'kwargs': {}, u'eta': None, u'reply_to': u'950dab7a-8608-37e0-991a-5e7c6dadbf4a', u'id': u'51fed74e-f0ce-4cad-9a3d-283b830939d6', u'headers': {}}) kwargs:{})
[2016-09-09 16:14:31,310: DEBUG/MainProcess] Task accepted: smartalec.tasks.match_loadfile_task[51fed74e-f0ce-4cad-9a3d-283b830939d6] pid:25239
[2016-09-09 16:15:26,475: ERROR/MainProcess] Task smartalec.tasks.match_loadfile_task[51fed74e-f0ce-4cad-9a3d-283b830939d6] raised unexpected: DatabaseError('<cx_Oracle._Error object at 0x36c9d50>',)
Traceback (most recent call last):
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/celery/app/trace.py", line 240, in trace_task
    R = retval = fun(*args, **kwargs)
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/celery/app/trace.py", line 438, in __protected_call__
    return self.run(*args, **kwargs)
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/smartalec/tasks.py", line 14, in match_loadfile_task
    load_file = LoadFile.objects.get(pk=loadfile_pk)
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/models/manager.py", line 85, in manager_method
    return getattr(self.get_queryset(), name)(*args, **kwargs)
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/models/query.py", line 379, in get
    num = len(clone)
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/models/query.py", line 238, in __len__
    self._fetch_all()
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/models/query.py", line 1087, in _fetch_all
    self._result_cache = list(self.iterator())
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/models/query.py", line 54, in __iter__
    results = compiler.execute_sql()
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/models/sql/compiler.py", line 824, in execute_sql
    sql, params = self.as_sql()
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/backends/oracle/compiler.py", line 22, in as_sql
    subquery=subquery,
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/models/sql/compiler.py", line 376, in as_sql
    where, w_params = self.compile(self.where) if self.where is not None else ("", [])
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/models/sql/compiler.py", line 353, in compile
    sql, params = node.as_sql(self, self.connection)
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/models/sql/where.py", line 79, in as_sql
    sql, params = compiler.compile(child)
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/models/sql/compiler.py", line 353, in compile
    sql, params = node.as_sql(self, self.connection)
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/models/lookups.py", line 158, in as_sql
    rhs_sql = self.get_rhs_op(connection, rhs_sql)
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/models/lookups.py", line 162, in get_rhs_op
    return connection.operators[self.lookup_name] % rhs
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/backends/oracle/base.py", line 80, in __get__
    instance.cursor().close()
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/backends/base/base.py", line 233, in cursor
    cursor = self.make_cursor(self._cursor())
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/backends/base/base.py", line 204, in _cursor
    self.ensure_connection()
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/backends/base/base.py", line 199, in ensure_connection
    self.connect()
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/utils.py", line 94, in __exit__
    six.reraise(dj_exc_type, dj_exc_value, traceback)
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/backends/base/base.py", line 199, in ensure_connection
    self.connect()
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/backends/base/base.py", line 171, in connect
    self.connection = self.get_new_connection(conn_params)
  File "/opt/tcida/virtualenv/smartalec/lib/python2.7/site-packages/django/db/backends/oracle/base.py", line 216, in get_new_connection
    return Database.connect(conn_string, **conn_params)
DatabaseError: <cx_Oracle._Error object at 0x36c9d50>

Does Oracle have any logs? Seems like there's an error message missing there, maybe they could provide more information. — asksol, Sep 09 '16 at 18:10

score 0 · Accepted Answer · answered Sep 12 '16 at 14:16

Ensure the user under which celery is running (which should be user with a shell, and by convention is called celery) has TNS_ADMIN set in its environment.

If you're running the celery service through systemd then it will be controlled with a file named celery.service with a path something like /etc/systemd/system/celery.service, and permissions 644. In that file under the [Service] section, use one of the directives Environment to set environment files directly or EnvironmentFile to use a file of environment variables.

Also be sure to understand the difference between services celery and celeryd, I don't really know what it is myself, but they can't be used interchangeably, as you were/I was doing.

DatabaseError between Oracle and Django with Celery

1 Answers1