Instrument logs in Celery tasks

[jeremydvoss]

Before opening a feature request against this repo, consider whether the feature should/could be implemented in the other OpenTelemetry client libraries. If so, please open an issue on opentelemetry-specification first.

Steps to reproduce:

1. Instrument logging
2. Log outside of celery task
3. Log inside of celery task
4. Trigger celery task
5. Notice that the log from inside the task is not captured

Example:

from fastapi import FastAPI
from celery import Celery
import logging


logging.basicConfig(level=logging.INFO)
app = FastAPI()
celery = Celery('tasks', broker='redis://localhost:6379/0')
@app.get('/')
def root():
    #This log is captured
    logging.info(f'Begin Task')
    task = count_to_10000.delay()
    return {'task_id': task.id}
@celery.task
def count_to_10000():
    for i in range(1, 10001):
        if i % 1000 == 0:
            #This log not captured
            logging.info(f'Count: {i}')
        else:
            pass
    return 'Counting complete!'

Is your feature request related to a problem? Yes. Celery tasks can seemingly use the same longer as code outside a celery task. Yet, the logs from within the task do not appear to be captured.

Describe the solution you'd like The logging instrumentation (or perhaps the celery instrumentation) is updated to somehow capture logs from inside celery tasks.

Describe alternatives you've considered I have not found alternatives.

Additional context Datadog seems to have the same issue

[jeremydvoss]

From the way celery tasks are written, it seems like they should be referencing the same logger as code outside the task. My guess is that celery does some level of abstraction whereby logs do not actually go through that logger in the traditional way. Investigating.

[jeremydvoss]

Parallel issue in OpenCensus: https://github.com/census-instrumentation/opencensus-python/issues/900

[kevinco26]

Hi Jeremy, any update on this? My whole backend architecture relies on Celery and not being able to log events/exceptions to azure is making me choose a different provider like Sentry..

For added context, I'm able to see logs if I log them OUTSIDE a celery task. The minute I put them inside my celery task they don't get logged to azure.

This works (Code is in my Celery.py file that has all the tasks, but it's not inside any particular task):

from logging import getLogger
from opencensus.ext.azure.log_exporter import AzureLogHandler
application_insights_connection_string= '<key>'
logger = getLogger(__name__)
handler = AzureLogHandler(connection_string=application_insights_connection_string)
logger.addHandler(handler)
logger.exception("test exception") 

This doesn't emit anything to azure.

@app.task
def simple_task():
    logger.exception("[Exception] from task")

[oldium]

Are you using worker_hijack_root_logger=False in the Celery setup? It seems this feature is not compatible with custom logger setup, so we had to disable it in our project.

See also answer https://stackoverflow.com/a/48370737/7080036 for additional tips.

Edit: I see that you are not instrumenting root logger, so this might be unrelated. But with worker_hijack_root_logger=True (default) the Celery empties handlers of root, celery, celery.task and celery.redirected loggers, so beware of this.

[oldium]

But if you are talking about OpenTelemetry logs forwarding, which is done through the root logger handler, the worker_hijack_root_logger value is important. If it is True (default), the OpenTelemetry handler is removed from the root logger, so nothing gets forwarded.

Similarly, if you would like to forward logs via OpenTelemetry from celery.task logger (loggers obtained via get_task_logger calls), this will not work, because the logger is set with logger.propagate=False, which disables sending log records to the parent log handlers, so the OpenTelemetry handler installed in the root logger will not receive it. I have an autoinstrumentation fix for that, though.