Kallithea issues archive

Issue #347: AttributeError: 'DisabledBackend' object has no attribute '_get_task_meta_for'

Reported by: Brandon Jones
State: resolved
Created on: 2019-09-17 05:03
Updated on: 2020-03-01 21:09

Description

I can’t seem to get Celery 3.1.26.post2 to play nice with Kallithea 0.4.1. I have tried multiple different configurations for the backend (rpc, amqp, db) to no avail. Here is my stack trace:

Sep 17 00:17:01 wti-repos kallithea[2218]: 2019-09-17 00:17:01.678 DEBUG [amqp] 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$
Sep 17 00:17:01 wti-repos kallithea[2218]: 2019-09-17 00:17:01.679 DEBUG [amqp] Open OK!
Sep 17 00:17:01 wti-repos kallithea[2218]: 2019-09-17 00:17:01.679 DEBUG [amqp] using channel_id: 1
Sep 17 00:17:01 wti-repos kallithea[2218]: 2019-09-17 00:17:01.680 DEBUG [amqp] Channel open
Sep 17 00:17:03 wti-repos kallithea[2218]: Traceback (most recent call last):
Sep 17 00:17:03 wti-repos kallithea[2218]:   File "/srv/kallithea/venv/lib/python2.7/site-packages/tg/appwrappers/session.py", line 71, in __call__
Sep 17 00:17:03 wti-repos kallithea[2218]:     response = self.next_handler(controller, environ, context)
Sep 17 00:17:03 wti-repos kallithea[2218]:   File "/srv/kallithea/venv/lib/python2.7/site-packages/tg/appwrappers/i18n.py", line 71, in __call__
Sep 17 00:17:03 wti-repos kallithea[2218]:     return self.next_handler(controller, environ, context)
Sep 17 00:17:03 wti-repos kallithea[2218]:   File "/srv/kallithea/venv/lib/python2.7/site-packages/tg/wsgiapp.py", line 285, in _dispatch
Sep 17 00:17:03 wti-repos kallithea[2218]:     return controller(environ, context)
Sep 17 00:17:03 wti-repos kallithea[2218]:   File "/srv/kallithea/venv/lib/python2.7/site-packages/kallithea/lib/base.py", line 539, in __call__
Sep 17 00:17:03 wti-repos kallithea[2218]:     return super(BaseController, self).__call__(environ, context)
Sep 17 00:17:03 wti-repos kallithea[2218]:   File "/srv/kallithea/venv/lib/python2.7/site-packages/tg/controllers/dispatcher.py", line 119, in __call__
Sep 17 00:17:03 wti-repos kallithea[2218]:     response = self._perform_call(context)
Sep 17 00:17:03 wti-repos kallithea[2218]:   File "/srv/kallithea/venv/lib/python2.7/site-packages/tg/controllers/dispatcher.py", line 108, in _perform_call
Sep 17 00:17:03 wti-repos kallithea[2218]:     r = self._call(action, params, remainder=remainder, context=context)
Sep 17 00:17:03 wti-repos kallithea[2218]:   File "/srv/kallithea/venv/lib/python2.7/site-packages/tg/controllers/decoratedcontroller.py", line 131, in _call
Sep 17 00:17:03 wti-repos kallithea[2218]:     output = controller_caller(context_config, bound_controller_callable, remainder, params)
Sep 17 00:17:03 wti-repos kallithea[2218]:   File "/srv/kallithea/venv/lib/python2.7/site-packages/tg/decorators.py", line 44, in _decorated_controller_caller
Sep 17 00:17:03 wti-repos kallithea[2218]:     return application_controller_caller(tg_config, controller, remainder, params)
Sep 17 00:17:03 wti-repos kallithea[2218]:   File "/srv/kallithea/venv/lib/python2.7/site-packages/tg/configuration/app_config.py", line 127, in call_controller
Sep 17 00:17:03 wti-repos kallithea[2218]:     return controller(*remainder, **params)
Sep 17 00:17:03 wti-repos kallithea[2218]:   File "</srv/kallithea/venv/local/lib/python2.7/site-packages/decorator.pyc:decorator-gen-15>", line 2, in repo_check
Sep 17 00:17:03 wti-repos kallithea[2218]:
Sep 17 00:17:03 wti-repos kallithea[2218]:   File "/srv/kallithea/venv/lib/python2.7/site-packages/kallithea/lib/auth.py", line 797, in __wrapper
Sep 17 00:17:03 wti-repos kallithea[2218]:     return func(*fargs, **fkwargs)
Sep 17 00:17:03 wti-repos kallithea[2218]:   File "</srv/kallithea/venv/local/lib/python2.7/site-packages/decorator.pyc:decorator-gen-14>", line 2, in repo_check
Sep 17 00:17:03 wti-repos kallithea[2218]:
Sep 17 00:17:03 wti-repos kallithea[2218]:   File "/srv/kallithea/venv/lib/python2.7/site-packages/kallithea/lib/base.py", line 627, in jsonify
Sep 17 00:17:03 wti-repos kallithea[2218]:     data = func(*args, **kwargs)
Sep 17 00:17:03 wti-repos kallithea[2218]:   File "/srv/kallithea/venv/lib/python2.7/site-packages/kallithea/controllers/admin/repos.py", line 189, in repo_check
Sep 17 00:17:03 wti-repos kallithea[2218]:     if task.failed():
Sep 17 00:17:03 wti-repos kallithea[2218]:   File "/srv/kallithea/venv/lib/python2.7/site-packages/celery/result.py", line 267, in failed
Sep 17 00:17:03 wti-repos kallithea[2218]:     return self.state == states.FAILURE
Sep 17 00:17:03 wti-repos kallithea[2218]:   File "/srv/kallithea/venv/lib/python2.7/site-packages/celery/result.py", line 394, in state
Sep 17 00:17:03 wti-repos kallithea[2218]:     return self._get_task_meta()['status']
Sep 17 00:17:03 wti-repos kallithea[2218]:   File "/srv/kallithea/venv/lib/python2.7/site-packages/celery/result.py", line 339, in _get_task_meta
Sep 17 00:17:03 wti-repos kallithea[2218]:     return self._maybe_set_cache(self.backend.get_task_meta(self.id))
Sep 17 00:17:03 wti-repos kallithea[2218]:   File "/srv/kallithea/venv/lib/python2.7/site-packages/celery/backends/base.py", line 307, in get_task_meta
Sep 17 00:17:03 wti-repos kallithea[2218]:     meta = self._get_task_meta_for(task_id)
Sep 17 00:17:03 wti-repos kallithea[2218]: AttributeError: 'DisabledBackend' object has no attribute '_get_task_meta_for'

Attachments

Comments

Comment by Thomas De Schampheleire, on 2019-09-18 06:26

Could you share the part of your .ini file relating to celery?

The error is a result of the backend not being correctly configured.

What did you change since before? Is it the first time you enable Celery?

Comment by Brandon Jones, on 2019-09-18 11:29

Here are the relevant entries in my INI file - however, I have tried multiple different configurations to no avail - all configurations would return the same error

celery.imports = kallithea.lib.celerylib.tasks
celery.accept.content = pickle
celery.result.backend = db+sqlite:///results.db

I have also tried rpc:// and amqp:// for the celery.result.backend entry. The celery.result.backend entry above is used in an example in the documentation for Celery 3.1.2.5 - https://docs.celeryproject.org/en/3.1/configuration.html

Comment by Thomas De Schampheleire, on 2019-09-18 11:48

The values provided in e.g. development.ini are:

## Example: connect to the virtual host 'rabbitmqhost' on localhost as rabbitmq:
broker.url = amqp://rabbitmq:qewqew@localhost:5672/rabbitmqhost

celery.imports = kallithea.lib.celerylib.tasks
celery.accept.content = pickle
celery.result.backend = amqp
celery.result.dburi = amqp://
celery.result.serialier = json

Here the backend and dburi are separate values, and backend is a simple word. The doc you refer to says:

CELERY_RESULT_DBURI

This setting is no longer used as it’s now possible to specify the database URL directly in the CELERY_RESULT_BACKEND setting.

but I have never used it this way.

Do you still have a (perhaps empty) ‘celery.result.dburi’ setting in your ini file, or did you remove it?

I’m using ‘backend = amqp’ and ‘dburi = amqp://' (i.e. empty) with a slightly older Kallithea version and that works. The amqp broker is rabbitmq in my case.

Could you first try with a configuration as in development.ini?

Comment by Brandon Jones, on 2019-09-18 12:03

I have celery.result.dburi commented out in my configuration. I started out with the default configuration which didn’t work, which is why I continued to make changes to see if there was some combination that worked.

Using the exact values in the default development.ini (swapped out for my local rabbitmq server and credentials), I am presented with the same error when trying to create a repository through the web interface. Here are my log entries in graylog:

2019-09-18 07:56:53.631 DEBUG [amqp] Channel open
2019-09-18 07:56:53.630 DEBUG [amqp] using channel_id: 1
2019-09-18 07:56:53.629 DEBUG [amqp] Open OK!
2019-09-18 07:56:53.628 DEBUG [amqp] 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-2017 Pivotal Software, Inc.', u'capabilities': {u'exchange_exchange_bindings': True, u'connection.blocked': True, u'authentication_failure_close': True, u'direct_reply_to': True, u'basic.nack': True, u'per_consumer_qos': True, u'consumer_priorities': True, u'consumer_cancel_notify': True, u'publisher_confirms': True}, u'cluster_name': u'rabbit@wti-repos', u'platform': u'Erlang/OTP', u'version': u'3.6.10'}, mechanisms: [u'PLAIN', u'AMQPLAIN'], locales: [u'en_US']

File "/srv/kallithea/venv/lib/python2.7/site-packages/celery/result.py", line 267, in failed
return self.state == states.FAILURE
File "/srv/kallithea/venv/lib/python2.7/site-packages/celery/result.py", line 339, in _get_task_meta
AttributeError: 'DisabledBackend' object has no attribute '_get_task_meta_for'

Comment by Thomas De Schampheleire, on 2019-09-18 20:03

Ok, I verified that celery with amqp/rabbitmq works correctly at my end. Celery version 3.1.26.post2. Rabbitmq 3.7.17 (docker container).

Let’s take a step back to fill in the details, I will be assuming amqp below as this is what I verified. Once this works we could go back to whatever you really want.

When do you get the reported stack trace? Is it as soon as you start up celery? Or later when an actual task is run?

How do you start celery? It should be with: kallithea-cli celery-run -c <inifile>

In case of rabbitmq, which version are you using?

Are you using docker at all, or is this a native installation?

I suggest adding some traces in the celery code to understand the issue better. In your virtualenv, edit file: lib/python2.7/site-packages/celery/backends/__init__.py , specifically in methods get_backend_cls and get_backend_by_url. As you can see in the first function, if backend passed as argument is None, then the disabled backend is used, which maps on DisabledBackend.

Comment by Brandon Jones, on 2019-09-19 16:44

I get the stack trace when I try to create a repository, specifically.

I start Celery the way just as you mentioned, running as a service in Ubuntu.

I am not using Docker - this is a native installation. Last time I tried to setup Kallithea with Docker I just couldn’t find enough useful documentation to make the process worth my time.

I was at RabbitMQ version 3.6.10, but I went ahead and moved to RabbitMQ version 3.7.17 (and Erlang 22.0.7) to match your configuration. I am still getting this error every time I try to create a repository.

I will try to do some stack tracing when I get a chance to see if I can figure anything else out. I’m not opposed to moving to a docker container if RabbitMQ and Celery work out-of-the-box, but again, I felt like there was a lack of information on how to set that up.

Comment by Thomas De Schampheleire, on 2019-09-19 19:57

You shouldn’t need docker for this. I could explain it more later, but it is not necessary at all, it won’t fix things. I think there is a configuration issue.

Curiously, the first time I created a repo I did get the same error as you. At that time my config file had a bogus setting “backend=amqp://foobar” . Then I tried out different settings and things worked. However, later I could no longer reproduce it even with the foobar setting.

However, during the testing I found differences depending on whether only celery-run was restarted after changing a setting, or both kallithea and celery-run. Both of them should be restarted when the celery settings are changed, are you doing that?

Comment by Brandon Jones, on 2019-09-19 20:20

Right, I'm aware of what Docker is and that I don't need it…. It might just work better than it has been for me because I'm assuming the container has RabbitMQ and Celery

What does your amqp:// url look like for the back end?

And yes I've been restarting both services everytime

Comment by Thomas De Schampheleire, on 2019-09-22 18:04

These are the settings that work for me:

####################################
###        CELERY CONFIG        ####
####################################

use_celery = true

## Example: connect to the virtual host 'rabbitmqhost' on localhost as rabbitmq:
broker.url = amqp://rabbitmq:qewqew@localhost:5672/rabbitmqhost

celery.imports = kallithea.lib.celerylib.tasks
celery.accept.content = pickle
celery.result.backend = amqp
celery.result.dburi = amqp://
celery.result.serialier = json

#celery.send.task.error.emails = true
#celery.amqp.task.result.expires = 18000

celeryd.concurrency = 2
celeryd.max.tasks.per.child = 1

## If true, tasks will never be sent to the queue, but executed locally instead.
celery.always.eager = false

The docker image I was referring to is only for rabbitmq, i.e. I just did:

docker run --rm -d --hostname my-rabbit --name some-rabbit -e RABBITMQ_DEFAULT_USER=rabbitmq -e RABBITMQ_DEFAULT_PASS=qewqew -e RABBITMQ_DEFAULT_VHOST=rabbitmqhost -p 5672:5672 rabbitmq

Outside of docker, I just ran celery-run normally.

In my work instance, we have everything in docker, also in separate containers: one for postgresql, one for rabbitmq, one for kallithea, one for celery.

Comment by Brandon Jones, on 2019-09-23 22:18

What all is Celery used for? Because besides getting an error when trying to create a repo, it seems as if most other things work fine. I am able to clone just fine, which I assume would be using Celery. Perhaps it is a bug specific to create repository, as you saw it on your initial try as well?

Comment by Thomas De Schampheleire, on 2019-09-25 08:17

Celery is used to handle some tasks asynchronously, outside of the web server process. Repository creation and forking, email sending are some examples. See kallithea/lib/celerylib/tasks.py for a full list. The web server process will continue immediately, the user will get a new web page, and the task continues in the background.

When Celery is not configured or not available, the tasks are handled in the main web server process, which means it will wait until the task is completed. In this sense, Celery is not mandatory.

But, for real deployment with more than a few users, it is recommended to configure Celery for performance.

Could you get any more info by adding traces in the Celery files as suggested?

Comment by Mads Kiilerich, on 2019-09-26 00:13

It seems like a celery bug that https://github.com/celery/celery/blob/master/celery/backends/base.py reference _get_task_meta_for in the base Backend class, but only implement it in BaseKeyValueStoreBackend and not in DisabledBackend.

I guess https://github.com/celery/celery/blob/master/celery/backends/base.py#L842 should have disabled get_task_meta instead?

But https://github.com/celery/celery/issues/4471#event-1783002644 was closed as not a bug … perhaps worth following up on …

I can however only reproduce the problem if I explicitly set celery.result.backend = disabled .

I wonder how your setup ends up with DisabledBackend. Can you try to debug your site-packages/celery/backends/__init__.py and figure out what comes in and out of these functions? (Perhaps just by adding print backend .)

The following works for me for testing with celery==3.1.26.post2:

use_celery = true
broker.url = sqla+sqlite:///broker.db

celery.imports = kallithea.lib.celerylib.tasks
celery.accept.content = pickle
celery.result.backend = db+sqlite:///results.db

(Note: sqla broker is not recommended - http://docs.celeryproject.org/en/3.1/getting-started/brokers/sqlalchemy.html#using-sqlalchemy )

Comment by Brandon Jones, on 2019-10-04 16:12

I added print backend to the appropriate place but I’m not sure where that is printing to, or if I have to setup some debug flag…

However, if I look at my Celery service, I can clearly see that Celery is getting the correct configuration (specifically looking at the results: sqlite:///results.db

Mads - what happens if you omit the celery.result.backend line (or just comment it out)? Do you still get the error? I’m starting to wonder if somehow kallithea-cli is not getting the appropriate configuration.

Comment by Thomas De Schampheleire, on 2019-10-04 18:36

The print should end up in the console where you started celery (via kallithea-cli). To make sure you are changing the right celery file, I suggest adding a syntax error. If things still start up, then the file you are changing is not the right one.

Comment by Brandon Jones, on 2019-10-04 19:18

OK, so I believe I am beyond the DisabledBackend error (although it seems like a bug in Celery that happens the first time I try to create a repo), but I am now presented with the following error:

[2019-10-04 14:52:16,648: ERROR/MainProcess] Task kallithea.lib.celerylib.create_repo[95a16e47-48d7-40ab-8519-cc668118d241] raised unexpected: OperationalError('(psycopg2.OperationalError) SSL error: decryption failed or bad record mac\n',)
Traceback (most recent call last):
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/celery/app/trace.py", line 240, in trace_task
    R = retval = fun(*args, **kwargs)
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/celery/app/trace.py", line 438, in __protected_call__
    return self.run(*args, **kwargs)
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/kallithea/lib/celerylib/__init__.py", line 69, in f_async
    f_org(*args, **kwargs)
  File "</srv/kallithea/venv/local/lib/python2.7/site-packages/decorator.pyc:decorator-gen-6>", line 2, in create_repo
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/kallithea/lib/celerylib/__init__.py", line 130, in __wrapper
    ret = func(*fargs, **fkwargs)
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/kallithea/lib/celerylib/tasks.py", line 333, in create_repo
    cur_user = User.guess_instance(cur_user)
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/kallithea/model/db.py", line 551, in guess_instance
    return super(User, cls).guess_instance(value, User.get_by_username)
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/kallithea/model/db.py", line 141, in guess_instance
    return cls.get(value)
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/kallithea/model/db.py", line 122, in get
    return cls.query().get(id_)
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 936, in get
    return self._get_impl(ident, loading.load_on_pk_identity)
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 1026, in _get_impl
    return db_load_fn(self, primary_key_identity)
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/loading.py", line 282, in load_on_pk_identity
    return q.one()
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 3039, in one
    ret = self.one_or_none()
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 3008, in one_or_none
    ret = list(self)
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/kallithea/lib/caching_query.py", line 81, in __iter__
    return Query.__iter__(self)
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 3081, in __iter__
    return self._execute_and_instances(context)
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 3106, in _execute_and_instances
    result = conn.execute(querycontext.statement, self._params)
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 980, in execute
    return meth(self, multiparams, params)
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/sql/elements.py", line 273, in _execute_on_connection
    return connection._execute_clauseelement(self, multiparams, params)
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1099, in _execute_clauseelement
    distilled_params,
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1240, in _execute_context
    e, statement, parameters, cursor, context
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1458, in _handle_dbapi_exception
    util.raise_from_cause(sqlalchemy_exception, exc_info)
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/util/compat.py", line 296, in raise_from_cause
    reraise(type(exception), exception, tb=exc_tb, cause=cause)
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1236, in _execute_context
    cursor, statement, parameters, context
  File "/srv/kallithea/venv/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 536, in do_execute
    cursor.execute(statement, parameters)
OperationalError: (psycopg2.OperationalError) SSL error: decryption failed or bad record mac
 [SQL: 'SELECT users.firstname AS users_firstname, users.email AS users_email, users.user_data AS users_user_data, users.user_id AS users_user_id, users.username AS users_username, users.password AS users_password, users.active AS users_active, users.admin AS users_admin, users.lastname AS users_lastname, users.last_login AS users_last_login, users.extern_type AS users_extern_type, users.extern_name AS users_extern_name, users.api_key AS users_api_key, users.inherit_default_permissions AS users_inherit_default_permissions, users.created_on AS users_created_on \nFROM users \nWHERE users.user_id = %(param_1)s'] [parameters: {'param_1': 3L}] (Background on this error at: http://sqlalche.me/e/e3q8)

SSL error: decryption failed or bad record mac

Doing some research online it sounds like it might be related to how WSGI is forking in waitress?

https://stackoverflow.com/questions/22752521/uwsgi-flask-sqlalchemy-and-postgres-ssl-error-decryption-failed-or-bad-reco

Comment by Samuel Delisle, on 2019-11-29 23:05

I think I have the same issue… Sometimes I can’t create repositories, and email notifications don’t work. If I restart the service, those queued tasks get executed.

When the service is started, everything works for a while. I printed some things in celery/backends/__init__.py, and everything looks normal:

$ kallithea-cli celery-run -c data/production.ini
[2019-11-29 17:37:35,299: WARNING/MainProcess] at get_backend_by_url
[2019-11-29 17:37:35,299: WARNING/MainProcess] url is
[2019-11-29 17:37:35,299: WARNING/MainProcess] None
[2019-11-29 17:37:35,300: WARNING/MainProcess] backend is
[2019-11-29 17:37:35,300: WARNING/MainProcess] amqp
[2019-11-29 17:37:35,300: WARNING/MainProcess] at get_backend_cls
[2019-11-29 17:37:35,300: WARNING/MainProcess] amqp
 -------------- celery@avr-vmkallithea v3.1.26.post2 (Cipater)
---- **** -----
--- * ***  * -- Linux-3.16.0-77-generic-x86_64-with-Ubuntu-16.04-xenial
-- * - **** ---
- ** ---------- [config]
- ** ---------- .> app:         __main__:0x7f0c2d698110
- ** ---------- .> transport:   amqp://kallithea:**@localhost:5672/kallitheavhost
- ** ---------- .> results:     amqp://
- *** --- * --- .> concurrency: 2 (prefork)
-- ******* ----
--- ***** ----- [queues]
 -------------- .> celery           exchange=celery(direct) key=celery

The “AttributeError: ‘DisabledBackend' object has no attribute '_get_task_meta_for' “ error pops up when creating a repository, but it still gets created. Emails also still work for a while, I’m not sure what triggers the backend to actually fail and not process anything anymore.

In the “nothing works” phase, rabbitmqctl would tell me there was a queue with 66 items in it (probably a bunch of emails waiting to be sent), but there was no consumer on the queue.

Comment by Thomas De Schampheleire, on 2019-12-06 20:45

I also sometimes see Celery tasks being blocked, mostly because emails are no longer sent, and restarting celery unblocks it. All queued mails then get processed.

But as far as I know I don’t have this DisabledBackend issue. I thus think they are separate problems.

Comment by Mads Kiilerich, on 2020-01-03 22:38

I wonder if https://stackoverflow.com/questions/54134216/airflow-scheduler-is-throwing-out-an-error-disabledbackend-object-has-no-att/54904586#54904586 could explain a part of what is discussed here.

Also, there are indications that celery itself isn’t multithreaded and needs locking … but I”m not sure where, and I doubt that could explain what is reported here.

Comment by vyom, on 2020-02-12 03:04

This settings did not help than I tried to look further into it. In Kallithea you use celerypylons package for Celery tasks which has a code for reading the config in:

def celery_config(config):
    """Return Celery config object populated from relevant settings in a config dict, such as tg.config"""

    # Verify .ini file configuration has been loaded
    assert config['celery.imports'] == 'kallithea.lib.celerylib.tasks', 'Kallithea Celery configuration has not been loaded'

    class CeleryConfig(object):
        pass

    celery_config = CeleryConfig()

    PREFIXES = """ADMINS BROKER CASSANDRA CELERYBEAT CELERYD CELERYMON CELERY EMAIL SERVER""".split()
    LIST_PARAMS = """CELERY_IMPORTS ADMINS ROUTES CELERY_ACCEPT_CONTENT""".split()

    for config_key, config_value in sorted(config.items()):
        celery_key = config_key.replace('.', '_').upper()
        if celery_key.split('_', 1)[0] not in PREFIXES:
            continue
        if not isinstance(config_value, str):
            continue
        if celery_key in LIST_PARAMS:
            celery_value = config_value.split()
        elif config_value.isdigit():
            celery_value = int(config_value)
        elif config_value.lower() in ['true', 'false']:
            celery_value = config_value.lower() == 'true'
        else:
            celery_value = config_value
        setattr(celery_config, celery_key, celery_value)
    return celery_config

If instead of celerypylons you used TurboGears 2 Celery Integration, this errors might go away. Example configuration for this in ini file is:

#celery config
celery.CELERY_TASK_SERIALIZER = json
celery.CELERY_RESULT_SERIALIZER = json
celery.CELERY_ACCEPT_CONTENT = json
celery.CELERY_TIMEZONE = UTC
celery.BROKER_URL = mongodb://localhost:27017/dbname
celery.CELERY_RESULT_BACKEND = mongodb://localhost:27017/dbname
celery.CELERYD_POOL = celery.concurrency.threads.TaskPool
celery.CELERY_INCLUDE = myproject.lib.celery.tasks
celery.CELERYD_CONCURRENCY = 3
celery.WITHOUT_GOSSIP = true
celery.WITHOUT_HEARTBEAT = true
celery.WITHOUT_MINGLE = true

Comment by Mads Kiilerich, on 2020-02-12 13:32

I agree the celery_config is odd - that is inherited cruft. But I doubt tgext.celery by itself will fix the problem. If anything, I guess it could be some of the additional values that make a difference - but they could also be put in the .ini with the current scheme. You can add some print statements to celery_config to verify what it actually is setting.

Comment by Thomas De Schampheleire, on 2020-02-14 21:11

I again tried reproducing this issue.

I can reproduce it when I set ‘dburi’ to an invalid setting and don’t set the ‘backend’:

#celery.result.backend = amqp://
celery.result.dburi = amqp://foobar

In this case, after restarting ‘kallithea-cli celery-run’, I see:

-- * - **** --- 
- ** ---------- [config]
- ** ---------- .> app:         __main__:0x7f461c135ac8
- ** ---------- .> transport:   amqp://rabbitmq:**@localhost:5672/rabbitmqhost
- ** ---------- .> results:     disabled://
- *** --- * --- .> concurrency: 2 (prefork)
-- ******* ---- 
--- ***** ----- [queues]
 -------------- .> celery           exchange=celery(direct) key=celery

(note the results: disabled://)

and then I will get the ‘DisabledBackend’ error during repository creation.

If I change the config to:

celery.result.backend = amqp://foobar
# no celery.result.dburi

then it actually works, and the output in the celery log is:

-- * - **** --- 
- ** ---------- [config]
- ** ---------- .> app:         __main__:0x7f14ee62fb00
- ** ---------- .> transport:   amqp://rabbitmq:**@localhost:5672/rabbitmqhost
- ** ---------- .> results:     amqp://
- *** --- * --- .> concurrency: 2 (prefork)
-- ******* ---- 
--- ***** ----- [queues]
 -------------- .> celery           exchange=celery(direct) key=celery

Note that in commit 34a59bfcebb1, the ‘dburi’ setting was already removed from our ini files, as it is deprecated in celery: https://docs.celeryproject.org/en/3.1/configuration.html#celery-result-dburi

Unless someone can report that they still get AttributeError: 'DisabledBackend' object has no attribute '_get_task_meta_for' if you use the below config, we will assume this issue is solved.

celery.result.backend = amqp://
# NO configuration for celery.result.dburi

In case you do have see this issue again with above config, please make sure that both the main kallithea app as kallithea-cli celery-run are restarted based on these ini settings. If you still see the issue then, then please report your configuration here.

Comment by Mads Kiilerich, on 2020-02-15 11:46

But what does results: amqp:// actually mean? Is it using the broker queue backwards, for results? Or is it using the default connection - something like guest on localhost on queue/vhost /?

Comment by Thomas De Schampheleire, on 2020-02-15 12:22

I don’t actually know how celery works and what these results are or if we actually use it.

Comment by vyom, on 2020-02-16 01:00

I enabled celery and it still gives an error creating a fork after showing this screen for a while. Not sure what it is waiting for when celery is enabled. It does not have any logs in either celery or kallithea.

Comment by Mads Kiilerich, on 2020-02-16 01:06

I see logs with tail -f /var/log/rabbitmq/*.log , and also on stdout when launching the worker as kallithea-cli celery-run -c my.ini -- --loglevel=DEBUG

As hinted above, I don’t see how celery.result.backend = amqp:// can work. I have seen more success with celery.result.backend = db+sqlite:///results.db .

Comment by vyom, on 2020-02-17 02:02

@Mads K In my specific case I did setup you are right celery.result.backend=amqp:// will not work, in python 2 my settings did work only during fork it gave an error.

celery.imports = kallithea.lib.celerylib.tasks
celery.accept.content = pickle
celery.result.backend = redis://localhost:6379/0
#celery.result.dburi =
celery.result.serialier = json

Based on Thomas’s advice I changed the settings to:

celery.imports = kallithea.lib.celerylib.tasks
celery.accept.content = json
celery.result.backend = redis://localhost:6379/0
celery.result.serialier = json

Still it did not work where I used redis and related libraries for backend, will now try sqlite.

Comment by vyom, on 2020-02-17 02:15

After restarting the worker as recommended by Mads, it still has an error:

Feb 17 10:08:23 kallithea-5-2 kallithea-cli[15297]: body: b'\x80\x02}q\x00(X\x04\x00\x00\x00taskq\x01X(\x00\x00\x00kallithea.lib.celerylib.create_repo_forkq\x02X\x02\x00\x00\x00idq\x03X$\x00\x00\x0035ba452e-f8c6-493f-b287-71601ac4e522q\x0
Feb 17 10:08:23 kallithea-5-2 kallithea-cli[15297]: Traceback (most recent call last):
Feb 17 10:08:23 kallithea-5-2 kallithea-cli[15297]:   File "/home/kallithea/projects/kallithea/venv3/lib/python3.6/site-packages/kombu/messaging.py", line 592, in _receive_callback
Feb 17 10:08:23 kallithea-5-2 kallithea-cli[15297]:     decoded = None if on_m else message.decode()
Feb 17 10:08:23 kallithea-5-2 kallithea-cli[15297]:   File "/home/kallithea/projects/kallithea/venv3/lib/python3.6/site-packages/kombu/message.py", line 142, in decode
Feb 17 10:08:23 kallithea-5-2 kallithea-cli[15297]:     self.content_encoding, accept=self.accept)
Feb 17 10:08:23 kallithea-5-2 kallithea-cli[15297]:   File "/home/kallithea/projects/kallithea/venv3/lib/python3.6/site-packages/kombu/serialization.py", line 174, in loads
Feb 17 10:08:23 kallithea-5-2 kallithea-cli[15297]:     raise self._for_untrusted_content(content_type, 'untrusted')
Feb 17 10:08:23 kallithea-5-2 kallithea-cli[15297]: kombu.exceptions.ContentDisallowed: Refusing to deserialize untrusted content of type pickle (application/x-python-serialize)

Comment by vyom, on 2020-02-17 02:32

When celery settings are following it works and creates the fork as expected but throws an error:

Celery Settings

## Example: connect to the virtual host 'rabbitmqhost' on localhost as rabbitmq:
broker.url = amqp://kallithea:testing@localhost:5672/kallithea

celery.imports = kallithea.lib.celerylib.tasks
celery.accept.content = pickle
celery.result.backend = db+sqlite:///results.db
#celery.result.backend = redis://localhost:6379/0
celery.result.serialier = json
celery.task.serialier = json

celery.send.task.error.emails = true
celery.amqp.task.result.expires = 18000

celeryd.concurrency = 2
celeryd.max.tasks.per.child = 1

Error in logs:

Feb 17 10:27:08 kallithea-5-2 kallithea-cli[15631]: [2020-02-17 10:27:08,890: INFO/MainProcess] Received task: kallithea.lib.celerylib.create_repo_fork[41b15188-4fb3-48f5-9d14-15a9f6b8ee92]
Feb 17 10:27:08 kallithea-5-2 kallithea-cli[15631]: [2020-02-17 10:27:08,891: DEBUG/MainProcess] TaskPool: Apply <function _fast_trace_task at 0x7f3f2dc40598> (args:('kallithea.lib.celerylib.create_repo_fork', '41b15188-4fb3-48f5-9d14-15a
Feb 17 10:27:08 kallithea-5-2 kallithea-cli[15631]: [2020-02-17 10:27:08,892: DEBUG/MainProcess] Task accepted: kallithea.lib.celerylib.create_repo_fork[41b15188-4fb3-48f5-9d14-15a9f6b8ee92] pid:15643
Feb 17 10:27:09 kallithea-5-2 kallithea-cli[15631]: error: outgoing.pull_logger hook raised an exception: Environment variable KALLITHEA_EXTRAS not found
Feb 17 10:27:09 kallithea-5-2 kallithea-cli[15631]: (run with --traceback for stack trace)
Feb 17 10:27:09 kallithea-5-2 kallithea-cli[15631]: error: outgoing.kallithea_log_pull_action hook raised an exception: Environment variable KALLITHEA_EXTRAS not found
Feb 17 10:27:09 kallithea-5-2 kallithea-cli[15631]: (run with --traceback for stack trace)
Feb 17 10:27:09 kallithea-5-2 kallithea-cli[15631]: [2020-02-17 10:27:09,816: INFO/MainProcess] Task kallithea.lib.celerylib.create_repo_fork[41b15188-4fb3-48f5-9d14-15a9f6b8ee92] succeeded in 0.9246168788522482s: None

When celery settings are different like:

## Example: connect to the virtual host 'rabbitmqhost' on localhost as rabbitmq:
broker.url = amqp://kallithea:testing@localhost:5672/kallithea

celery.imports = kallithea.lib.celerylib.tasks
celery.accept.content = pickle
celery.result.backend = amqp://
#celery.result.backend = redis://localhost:6379/0
celery.result.serialier = json
celery.task.serialier = json

celery.send.task.error.emails = true
celery.amqp.task.result.expires = 18000

celeryd.concurrency = 2
celeryd.max.tasks.per.child = 1

Error in logs:

Feb 17 10:34:24 kallithea-5-2 kallithea-cli[15779]: [2020-02-17 10:34:24,368: INFO/MainProcess] Received task: kallithea.lib.celerylib.create_repo_fork[0e7e199e-2741-4104-8494-d16871d557e5]
Feb 17 10:34:24 kallithea-5-2 kallithea-cli[15779]: [2020-02-17 10:34:24,369: DEBUG/MainProcess] TaskPool: Apply <function _fast_trace_task at 0x7f7258f40598> (args:('kallithea.lib.celerylib.create_repo_fork', '0e7e199e-2741-4104-8494-d16
Feb 17 10:34:24 kallithea-5-2 kallithea-cli[15779]: [2020-02-17 10:34:24,370: DEBUG/MainProcess] Task accepted: kallithea.lib.celerylib.create_repo_fork[0e7e199e-2741-4104-8494-d16871d557e5] pid:15790
Feb 17 10:34:24 kallithea-5-2 kallithea-cli[15779]: error: outgoing.pull_logger hook raised an exception: Environment variable KALLITHEA_EXTRAS not found
Feb 17 10:34:24 kallithea-5-2 kallithea-cli[15779]: (run with --traceback for stack trace)
Feb 17 10:34:24 kallithea-5-2 kallithea-cli[15779]: error: outgoing.kallithea_log_pull_action hook raised an exception: Environment variable KALLITHEA_EXTRAS not found
Feb 17 10:34:24 kallithea-5-2 kallithea-cli[15779]: (run with --traceback for stack trace)
Feb 17 10:34:25 kallithea-5-2 kallithea-cli[15779]: [2020-02-17 10:34:25,267: INFO/MainProcess] Task kallithea.lib.celerylib.create_repo_fork[0e7e199e-2741-4104-8494-d16871d557e5] succeeded in 0.897901217918843s: None

Comment by Mads Kiilerich, on 2020-02-17 17:56

I think the KALLITHEA_EXTRAS error “always” has been there and has been logged - the logs has just not been showed. After https://kallithea-scm.org/repos/kallithea/changeset/1e84580687919bdcc31e9186b9dee250e790237a , the error is exposed. It would be nice to get fixed, but it seems to work anyway.

The “Refusing to deserialize untrusted content of type pickle“ error seems to be due to typo in “serialize” fixed in https://kallithea-scm.org/repos/kallithea/changeset/8169770a4f2c967d4c41aca7c7fb31e90fbec989 . It would be nice if you could test again with the right spelling.

Thanks for confirming that celery.result.backend=amqp:// doesn’t work for you. That helps align the understanding of what is going on. (Also, amqp for results seems to be desupported in celery 4.) I think we should change the default example configuration to use celery.result.backend = db+sqlite:///results.db - what’s your thoughs about that?

Comment by vyom, on 2020-02-24 02:27

In my case both settings work. So either will work in present case not tested with celery 4.1 so can’t say yet. But using sqlite is better given default is sqlite for db in general.

Settings 1:

## Example: connect to the virtual host 'rabbitmqhost' on localhost as rabbitmq:
broker.url = amqp://kallithea:testing@localhost:5672/kallithea

celery.imports = kallithea.lib.celerylib.tasks
celery.accept.content = json
celery.result.backend = db+sqlite:///results.db
celery.result.serializer = json
celery.task.serializer = json

celery.send.task.error.emails = true
celery.amqp.task.result.expires = 18000

celeryd.concurrency = 2
celeryd.max.tasks.per.child = 1

Settings 2:

## Example: connect to the virtual host 'rabbitmqhost' on localhost as rabbitmq:
broker.url = amqp://kallithea:testing@localhost:5672/kallithea

celery.imports = kallithea.lib.celerylib.tasks
celery.accept.content = json
celery.result.backend = amqp://
celery.result.serializer = json
celery.task.serializer = json

celery.send.task.error.emails = true
celery.amqp.task.result.expires = 18000

celeryd.concurrency = 2
celeryd.max.tasks.per.child = 1

Comment by Mads Kiilerich, on 2020-02-24 18:00

Thanks for testing.

I just pushed code for Upgrading to Celery 4. It would be great if you could confirm if that works for you too.

Comment by vyom, on 2020-02-25 07:12

Yes I tested it with Celery 4 it works fine and updated celery config is below. I think this issue can be resolved now.

How about the send email task settings, it was there in old one not in the new one?

####################################
###        CELERY CONFIG        ####
####################################

## Note: Celery doesn't support Windows.
use_celery = false

## Celery config settings from https://docs.celeryproject.org/en/4.4.0/userguide/configuration.html prefixed with 'cel
ery.'.

## Example: use the message queue on the local virtual host 'kallitheavhost' as the RabbitMQ user 'kallithea':
celery.broker_url = amqp://kallithea:thepassword@localhost:5672/kallitheavhost

celery.result.backend = db+sqlite:///celery-results.db

#celery.amqp.task.result.expires = 18000

celery.worker_concurrency = 2
celery.worker_max_tasks_per_child = 1

## If true, tasks will never be sent to the queue, but executed locally instead.
celery.task_always_eager = false

Comment by Thomas De Schampheleire, on 2020-02-25 07:54

The email settings are no longer supported in celery 4 and got removed in commit ecd3cf91b293 .

Comment by Mads Kiilerich, on 2020-02-25 18:18

(I assume testing actually used `use_celery=True` ?)

It would indeed be nice to use the same error reporting (for example by mail) everywhere. Since we use TurboGears for other error reporting, it would be nice to use the TG error handling “standalone”, also when running inside Celery, perhaps using something inspired by https://stackoverflow.com/a/45747117 .

But also, now we should get better logging from celery, so simple log monitoring might solve the use case.

Comment by Thomas De Schampheleire, on 2020-03-01 21:09

This problem is tested and reported to be solved now. If you have this problem, please first test with the latest version (today 'default' branch, will be part of 0.6.0) and make sure that you have regenerated a config file with the right celery settings.

Thanks to everyone involved in this issue for their help.