Django Celery 日志记录最佳实践答案

【问题标题】：Django Celery Logging Best PracticeDjango Celery 日志记录最佳实践
【发布时间】：2012-11-02 05:03:19
【问题描述】：

我正在尝试让 Celery 日志记录与 Django 一起工作。我在settings.py 中进行了日志设置以转到控制台（当我在Heroku 上托管时效果很好）。在每个模块的顶部，我有：

import logging
logger = logging.getLogger(__name__)

在我的 tasks.py 中，我有：

from celery.utils.log import get_task_logger
logger = get_task_logger(__name__)

这可以很好地记录来自任务的调用，我得到如下输出：

2012-11-13T18:05:38+00:00 app[worker.1]: [2012-11-13 18:05:38,527: INFO/PoolWorker-2] Syc feed is starting

但如果该任务随后调用另一个模块中的方法，例如queryset 方法，我得到重复的日志条目，例如

2012-11-13T18:00:51+00:00 app[worker.1]: [INFO] utils.generic_importers.ftp_processor process(): File xxx.csv already imported. Not downloaded
2012-11-13T18:00:51+00:00 app[worker.1]: [2012-11-13 18:00:51,736: INFO/PoolWorker-6] File xxx.csv already imported. Not downloaded

我想我可以使用

CELERY_HIJACK_ROOT_LOGGER = False

只使用Django 日志记录，但是当我尝试它时这不起作用，即使我确实让它工作，我也会失去我想要的"PoolWorker-6" 位。（顺便说一句，我不知道如何让任务名称显示在 Celery 的日志条目中，因为 the docs 似乎表明它应该这样做）。

我怀疑我在这里遗漏了一些简单的东西。

【问题讨论】：

相关的，也许是：Celery and Python's logging inside tasks
我确实看过。 get_task_logger() 位显然是执行 add.get_logger() 位的新方法
啊，确实，我的回答对于 Celery 3.0 来说已经过时了；因为我现在不使用芹菜，所以我没有意识到这一点。 :-)
Celery 3.0 使用两个记录器层次结构，有一个 celery 记录器，所有其他记录器都继承自（您可以使用 celery.utils.get_logger 创建一个新记录器，还有一个 celery.task 记录器，它也继承来自celery 记录器，但不会传播到其处理程序，这是因为它具有自定义日志记录格式（它包括任务 ID 等）。如果您手动设置日志记录，您应该使用自定义记录器配置它们celery.task的格式

标签： python django logging celery django-celery

【解决方案1】：

当您的记录器在“另一个模块”的开头初始化时，它会链接到另一个记录器。哪个处理您的消息。它可以是根记录器，或者通常我在 Django 项目中看到的 - 名称为 '' 的记录器。

最好的方法是覆盖你的日志配置：

LOGGING = {
    'version': 1,
    'disable_existing_loggers': True,
    'formatters': {
        'simple': {
            'format': '%(levelname)s %(message)s',
             'datefmt': '%y %b %d, %H:%M:%S',
            },
        },
    'handlers': {
        'console': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
            'formatter': 'simple'
        },
        'celery': {
            'level': 'DEBUG',
            'class': 'logging.handlers.RotatingFileHandler',
            'filename': 'celery.log',
            'formatter': 'simple',
            'maxBytes': 1024 * 1024 * 100,  # 100 mb
        },
    },
    'loggers': {
        'celery': {
            'handlers': ['celery', 'console'],
            'level': 'DEBUG',
        },
    }
}

from logging.config import dictConfig
dictConfig(LOGGING)

在这种情况下，我想它应该像你想象的那样工作。

附： dictConfig 在 Python2.7+ 中添加。

【讨论】：

我需要将 celery 日志记录到控制台而不是日志文件。这能用吗？
当然，streamHandler 将写入控制台。
您甚至可以设置最大 nr 的日志文件，在 maxBytes 之后添加 dict 中的属性：'backupCount': 10,

【解决方案2】：

要解决重复记录问题，对我有用的是在声明我的 settings.LOGGING dict 时将传播设置设置为 false

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'console': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
            'formatter': 'verbose'
        },
    },
    'formatters': {
        'verbose': {
            'format': '%(asctime)s %(levelname)s module=%(module)s, '
            'process_id=%(process)d, %(message)s'
        }
    },
    'loggers': {
        'my_app1': {
            'handlers': ['console'],
            'level': 'DEBUG',
            'propagate': False #this will do the trick
        },
        'celery': {
            'handlers': ['console'],
            'level': 'DEBUG',
            'propagate': True
        },
    }
}

假设您的 django 项目布局如下所示：
我的项目/
- 任务.py
- 电子邮件.py

假设您的一项任务调用了 email.py 中的某个函数；日志记录将发生在 email.py 中，然后该日志记录将传播到“父级”，在这种情况下，这恰好是您的 celery 任务。因此双重记录。但是将特定记录器的传播设置为 False 意味着对于该记录器/应用程序，其日志不会传播到父级，因此它们将不会是“双重”记录。默认情况下，“传播”设置为 True

这是关于父/子记录器的 link to the django docs 部分

【讨论】：

【解决方案3】：

令人不安的是，Celery 会干扰根记录器（这不是最佳实践，无法完全控制），但它不会以任何方式禁用您应用的自定义记录器，因此请使用您自己的处理程序名称并定义您的自己的行为，而不是尝试用 Celery 解决这个问题。 [无论如何，我喜欢将我的应用程序日志记录分开）。您可以对 Django 代码和 Celery 任务使用单独的处理程序或相同的处理程序，您只需在 Django LOGGING 配置中定义它们。将模块、文件名和 processName 的格式化参数添加到您的格式化程序中，以帮助您区分消息的来源。

[假设您在指向 Appender 的 LOGGING 设置值中为“yourapp”设置了一个处理程序 - 听起来您似乎知道这一点]。

views.py

log = logging.getLogger('yourapp')
def view_fun():
    log.info('about to call a task')
    yourtask.delay()

tasks.py

log = logging.getLogger('yourapp')
@task
def yourtask():
    log.info('doing task')

对于 Celery 生成的日志记录 - 如果需要，使用 celeryd 标志 --logfile 将 Celery 输出（例如，worker init、启动任务、任务失败）发送到单独的位置。或者，使用此处的其他答案，将“芹菜”记录器发送到您选择的文件。

注意：我不会使用 RotatingFileHandlers - 多进程应用程序不支持它们。来自另一个工具（如 logrotate）的日志轮换更安全，假设您在那里有多个进程，或者与 celery 工作人员共享相同的日志文件，则来自 Django 的日志记录也是如此。如果您使用多服务器解决方案，您可能希望在某个集中的地方进行日志记录。

【讨论】：

Celery 日志记录应该记录任务名称和消息。有没有办法让这个工作？因此，如果来自另一个模块的日志消息是从“你的任务”调用的，那么它会在日志消息中包含“你的任务”
尝试 log.info("执行任务 id %r, args: %r kwargs: %r" % (yourtask.request.id, yourtask.request.args, yourtask.request.kwargs))在你的任务函数中。
Celery 干扰根记录器的原因是因为有几个 3rd 方应用程序/库可以配置日志记录。在许多情况下，这导致用户没有输出。 Celery 用户仍然可以选择手动配置日志记录。

【解决方案4】：

也许它会对某人有所帮助，我的问题是将所有芹菜日志发送到 graylog。这是解决方案。

celery.py：

app.config_from_object('django.conf:settings', namespace='CELERY')


# ====== Magic starts
from celery.signals import setup_logging

@setup_logging.connect
def config_loggers(*args, **kwargs):
    from logging.config import dictConfig
    from django.conf import settings
    dictConfig(settings.LOGGING)
# ===== Magic ends


# Load task modules from all registered Django app configs.
app.autodiscover_tasks()

settings.py：

LOGGING = {
    'version': 1,
    'handlers': {
        'graypy': {
            'class': 'graypy.GELFTCPHandler',
            'host': GRAYLOG_HOST,
            'port': GRAYLOG_PORT,
        }
    },
    'loggers': {
        'my_project': {
            'handlers': ['graypy'],
            'level': 'INFO',
        },
        # ====== Magic starts
        'celery': {
            'handlers': ['graypy'],
            'level': 'INFO',
        }
        # ===== Magic ends
    }
}

【讨论】：