python - 在 AWS lambda 函数中获取日志两次

问题描述

我正在尝试创建一个集中模块来设置我的日志格式化程序，以便在我的 lambda 函数中的多个 python 模块之间共享。此功能最终将在本地本地设备上的 AWS Greengrass 上运行。

出于某种原因，当我添加自己的处理程序来格式化消息时，日志被输出了两次——一次在正确的日志级别，第二次在不正确的级别。

如果我使用标准的 python 记录器而不设置任何处理程序，它可以正常工作，例如

main.py：

import logging

logging.debug("test1")

cloudwatch logs：

12:28:42 [DEBUG]-main.py:38,test1

我的目标是在我的代码上有一个格式化程序，它将这些日志消息格式化为 JSON。然后，它们将被摄取到集中式日志数据库中。但是，当我这样做时，我会收到两次日志消息。

loghelper.py：

def setup_logging(name):

    formatter = logging.Formatter("%(name)s, %(asctime)s, %(message)s")

    handler = logging.StreamHandler(sys.stdout)
    handler.setFormatter(formatter)

    logger = logging.getLogger(name)

    if logger.handlers:
        for handler in logger.handlers:
            logger.removeHandler(handler)

    logger.setLevel(logging.DEBUG)
    logger.addHandler(handler)
    return logger

main.py：

import logging

logger = loghelper.setup_logging('main.test_function')

def test_function():
    logger.debug("test function log statement")

test_function()

现在运行 lambda 函数时，我在云监视日志中收到两次调试消息，如下所示：

cloudwatch logs：

12:22:53 [DEBUG]-main.py:5, test function log statement
12:22:53 [INFO]-__init__.py:880,main.test_function,2018-06-18 12:22:53,099, test function log statement

请注意：

第一个条目的级别正确，但格式错误。
第二个条目报告了错误的级别、错误的模块但格式正确。

我无法解释这种行为，并希望对可能导致它的原因有任何想法。我也不知道第 880 行存在哪个构造函数。这可能会对正在发生的事情有所了解。

参考：

设置全局格式化程序：如何在 python 中为整个程序定义一个记录器？
清除默认 lambda 日志处理程序：将 python 日志记录与 AWS Lambda 一起使用
创建全局记录器： Python：记录模块 - 全局

标签： pythonamazon-web-servicesloggingaws-lambdagreengrass

解决方案

AWS Lambda 还在根记录器上设置了一个处理程序，写入的任何内容都会stdout被捕获并记录为 level INFO。因此，您的日志消息被捕获两次：

由根记录器上的 AWS Lambda 处理程序（因为日志消息从嵌套的子记录器传播到根），并且此记录器配置了自己的格式。
通过 AWS Lambda 标准输出到信息记录器。

这就是为什么消息都以(asctime) [(levelname)]-(module):(lineno),信息开头的原因；根记录器配置为输出具有该格式的消息，写入标准输出的信息只是%(message)该输出的另一部分。

只是不要在 AWS 环境中设置处理程序，或者禁用将输出传播到根处理程序并让所有消息都INFO被 AWS 记录为消息；在后一种情况下，您自己的格式化程序可以levelname在输出中包含级别信息。

您可以使用禁用日志传播logger.propagate = False，此时您的消息只会传递给您的处理程序，而不是根处理程序。

另一种选择是仅依赖 AWS 根记录器配置。根据这篇优秀的逆向工程博客文章，根记录器配置为：

logging.Formatter.converter = time.gmtime
logger = logging.getLogger()
logger_handler = LambdaLoggerHandler()
logger_handler.setFormatter(logging.Formatter(
    '[%(levelname)s]\t%(asctime)s.%(msecs)dZ\t%(aws_request_id)s\t%(message)s\n',
    '%Y-%m-%dT%H:%M:%S'
))
logger_handler.addFilter(LambdaLoggerFilter())
logger.addHandler(logger_handler)

这将time.localtime转换器logging.Formatter替换为time.gmtime（因此时间戳使用 UTC 而不是本地时间），设置自定义处理程序以确保消息进入 Lambda 基础设施，配置格式，并添加仅aws_request_id向记录添加属性的过滤器对象（因此上述格式化程序可以包含它）但实际上并没有过滤任何东西。

您可以通过更新对象的属性来更改该处理程序上的格式化程序handler.formatter：

for handler in logging.getLogger().handlers:
    formatter = handler.formatter
    if formatter is not None and 'aws_request_id' in formatter._fmt:
        # this is the AWS Lambda formatter
        # formatter.datefmt => '%Y-%m-%dT%H:%M:%S'
        # formatter._style._fmt => 
        #    '[%(levelname)s]\t%(asctime)s.%(msecs)dZ'
        #    '\t%(aws_request_id)s\t%(message)s\n'

然后完全删除您自己的记录器处理程序。你确实要小心这个；AWS Lambda 基础设施很可能依赖于使用的特定格式。您在问题中显示的输出不包括日期组件（字符串的%Y-%m-%dT一部分formatter.datefmt），这可能意味着格式已被解析出来并在数据的 Web 应用程序视图中呈现给您。

python - 在 AWS lambda 函数中获取日志两次

问题描述

解决方案

推荐阅读