Issue 1:
Checklist

I have checked the issues list

for similar or identical feature requests.

I have checked the pull requests list

for existing proposed implementations of this feature.

I have checked the commit log

to find out if the if the same feature was already implemented in the

master branch.

I have included all related issues and possible duplicate issues

in this issue (If there are none, check this box anyway).

Related Issues and Possible Duplicates

Related Issues

None

Possible Duplicates

None

Brief Summary

Design

Architectural Considerations

None

Proposed Behavior

Proposed UI/UX

Diagrams

N/A

Alternatives

None

Issue 2:
Checklist

I have verified that the issue exists against the master branch of Celery.

This has already been asked to the discussion group first.

I have read the relevant section in the

contribution guide

on reporting bugs.

I have checked the issues list

for similar or identical bug reports.

I have checked the pull requests list

for existing proposed fixes.

I have checked the commit log

to find out if the bug was already fixed in the master branch.

I have included all related issues and possible duplicate issues

in this issue (If there are none, check this box anyway).

Mandatory Debugging Information

I have included the output of celery -A proj report in the issue.

(if you are not able to do this, then at least specify the Celery

version affected).

I have verified that the issue exists against the master branch of Celery.

I have included the contents of pip freeze in the issue.

I have included all the versions of all the external dependencies required

to reproduce this bug.

Environment & Settings

Celery version: All

Steps to Reproduce

Required Dependencies

Minimal Python Version: N/A

Minimal Celery Version: N/A

Minimal Kombu Version: N/A

Minimal Broker Version: N/A

Minimal Result Backend Version: N/A

Minimal OS and/or Kernel Version: N/A

Minimal Broker Client Version: N/A

Minimal Result Backend Client Version: N/A

Python Packages

pip freeze Output:

pytest

Minimally Reproducible Test Case

from celery.signals import setup_logging

@setup_logging.connect
def on_setup_logging(sender, *args, **kwargs):
print("Hello")

import pytest

@pytest.fixture
def celery_enable_logging():
return False

def test_celery_logging(celery_worker):
@celery_worker.app.task
def test_task():
pass
celery_worker.reload([__name__])
test_task.apply_async().get()

Expected Behavior

No "Hello" is printed.

Actual Behavior

"Hello" is printed

Investigation

It appears that celery_enable_logging doesn't actually work at all. When it's enabled this code is executed:

@pytest.fixture()
def celery_app(request,
celery_config,
celery_parameters,
celery_enable_logging,
use_celery_app_trap):
"""Fixture creating a Celery application instance."""
mark = request.node.get_closest_marker('celery')
config = dict(celery_config, **mark.kwargs if mark else {})
with _create_app(enable_logging=celery_enable_logging,
use_trap=use_celery_app_trap,
parameters=celery_parameters,
**config) as app:
yield app

@contextmanager
def _create_app(enable_logging=False,
use_trap=False,
parameters=None,
**config):
# type: (Any, **Any) -> Celery
"""Utility context used to setup Celery app for pytest fixtures."""
parameters = {} if not parameters else parameters
test_app = TestApp(
set_as_current=False,
enable_logging=enable_logging,
config=config,
**parameters
)
with setup_default_app(test_app, use_trap=use_trap):
yield test_app

def TestApp(name=None, config=None, enable_logging=False, set_as_current=False,
log=UnitLogging, backend=None, broker=None, **kwargs):
"""App used for testing."""
from . import tasks # noqa
config = dict(deepcopy(DEFAULT_TEST_CONFIG), **config or {})
if broker is not None:
config.pop('broker_url', None)
if backend is not None:
config.pop('result_backend', None)
log = None if enable_logging else log
test_app = Celery(
name or 'celery.tests',
set_as_current=set_as_current,
log=log,
broker=broker,
backend=backend,
**kwargs)
test_app.add_defaults(config)
return test_app

class UnitLogging(symbol_by_name(Celery.log_cls)):
"""Sets up logging for the test application."""

def __init__(self, *args, **kwargs):
super(UnitLogging, self).__init__(*args, **kwargs)
self.already_setup = True

Specifically when celery_enable_logging is False then when the TestApp instance is initialized (with enable_logging=False), it proxies the call to the Celery constructor with UnitLogging as the log class. UnitLogging in turn sets self.already_setup = True in its constructor so that the logging system isn't initialized here:

def setup_logging_subsystem(self, loglevel=None, logfile=None, format=None,
colorize=None, hostname=None, **kwargs):
if self.already_setup:
return
...

The problem is that in the interim between when the UnitLogging instance is initialized and when the logging system should be setup, the worker does this:

def setup_app_for_worker(app, loglevel, logfile):
# type: (Celery, Union[str, int], str) -> None
"""Setup the app to be used for starting an embedded worker."""
app.finalize()
app.set_current()
app.set_default()
type(app.log)._setup = False
app.log.setup(loglevel=loglevel, logfile=logfile)

Note that the change to _setup actually undoes the work done in UnitLogging because Logging.already_setup is actually just a property over Logging._setup:

@class_property
def already_setup(self):
return self._setup

@already_setup.setter # noqa
def already_setup(self, was_setup):
self._setup = was_setup

So whether or not celery_enable_logging is True or False, the logging system is always setup as part of the celery_worker fixture. Removing this line of code:

type(app.log)._setup = False

Seems to fix the problem.