Google 云日志记录将 python INFO 消息显示为错误

Question

我有一个应用程序在谷歌云的 Kubernetes 中运行。该应用程序是使用 fastapi 用 python 编写的。来自该应用程序的日志通过谷歌云日志记录可见，但是它们的“服务器性”似乎被错误地翻译：虽然 fastapi 的访问日志正确地以“INFO”严重性写入，但从自定义记录器写入的任何消息都会显示为错误，即使它们是写入的通过logger.info电话。

我通过命令行选项将以下日志记录配置传递给 uvicorn --log-config：

{
  "version": 1,
  "disable_existing_loggers": false,
  "formatters": {
    "simple": {
      "format": "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
    },
    "default": {
      "()": "uvicorn.logging.DefaultFormatter",
      "datefmt": "%Y-%m-%dT%H:%M:%S",
      "format": "[%(asctime)s.%(msecs)04dZ] %(name)s %(levelprefix)s %(message).400s"
    },
    "access": {
      "()": "uvicorn.logging.AccessFormatter",
      "datefmt": "%Y-%m-%dT%H:%M:%S",
      "format": "[%(asctime)s.%(msecs)04dZ] %(name)s %(levelprefix)s %(message)s"
    }
  },
  "handlers": {
    "default": {
      "formatter": "default",
      "class": "logging.StreamHandler",
      "stream": "ext://sys.stderr"
    },
    "access": {
      "formatter": "access",
      "class": "logging.StreamHandler",
      "stream": "ext://sys.stdout"
    }
  },
  "loggers": {
    "uvicorn.error": {
      "level": "INFO",
      "handlers": ["default"],
      "propagate": false
    },
    "uvicorn.access": {
      "level": "INFO",
      "handlers": ["access"],
      "propagate": false
    },
    "uvicorn": {
      "level": "INFO",
      "handlers": ["default"],
      "propagate": false
    },
    "jsonrpc": {
      "level": "INFO",
      "handlers": ["default"],
      "propagate": false
    },
    "api": {
      "level": "INFO",
      "handlers": ["default"],
      "propagate": false
    }
  },
  "root": {
    "level": "INFO",
    "handlers": ["default"]
  }
}

所有uvicorn*记录器均已正确处理，但jsonrpc和api记录器始终在谷歌云中显示为“错误”。

按照google-cloud-logging的文档，我使用以下内容来设置云日志记录：

{
  "version": 1,
  "disable_existing_loggers": false,
  "formatters": {
    "simple": {
      "format": "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
    },
    "default": {
      "()": "uvicorn.logging.DefaultFormatter",
      "datefmt": "%Y-%m-%dT%H:%M:%S",
      "format": "[%(asctime)s.%(msecs)04dZ] %(name)s %(levelprefix)s %(message).400s"
    },
    "access": {
      "()": "uvicorn.logging.AccessFormatter",
      "datefmt": "%Y-%m-%dT%H:%M:%S",
      "format": "[%(asctime)s.%(msecs)04dZ] %(name)s %(levelprefix)s %(message)s"
    }
  },
  "handlers": {
    "default": {
      "formatter": "default",
      "class": "logging.StreamHandler",
      "stream": "ext://sys.stderr"
    },
    "access": {
      "formatter": "access",
      "class": "logging.StreamHandler",
      "stream": "ext://sys.stdout"
    }
  },
  "loggers": {
    "uvicorn.error": {
      "level": "INFO",
      "handlers": ["default"],
      "propagate": false
    },
    "uvicorn.access": {
      "level": "INFO",
      "handlers": ["access"],
      "propagate": false
    },
    "uvicorn": {
      "level": "INFO",
      "handlers": ["default"],
      "propagate": false
    },
    "jsonrpc": {
      "level": "INFO",
      "handlers": ["default"],
      "propagate": false
    },
    "api": {
      "level": "INFO",
      "handlers": ["default"],
      "propagate": false
    }
  },
  "root": {
    "level": "INFO",
    "handlers": ["default"]
  }
}

我缺少什么？我的配置文件有问题吗？这是预期的或已知的行为吗？

编辑：看来这里的部分问题是控制台处理程序转到的流。将默认处理程序切换到 stdout 并添加打印到 stderr 的错误处理程序似乎可以解决问题。

Answer 1

在这里发帖是因为我遇到了类似的问题，对于部署在 Vertex AI 端点后面的 Docker 容器，所有日志均显示错误严重性，并且此处没有可用的解决方案。以下代码为我解决了这个问题：

\n

import logging\nimport sys\n\ninfo_stream_handler = logging.StreamHandler(stream=sys.stdout)\ninfo_stream_handler.setLevel(logging.INFO)\ncloud_logger = logging.getLogger(\'cloudLogger\')\ncloud_logger.setLevel(logging.INFO)\ncloud_logger.addHandler(info_stream_handler)\ncloud_logger.propagate = False\n\ncloud_logger.info("Info Log Message")\n

\n

\n

• Vertex AI 将从模型容器记录 stdout\xc2\xa0and\xc2\xa0stderr\xc2\xa0streams ( https://cloud.google.com/vertex-ai/docs/predictions/online-prediction-logging )。

  \n
\n

• 首先，我一直在使用logging.basicConfig(level=logging.INFO)。

  \n
\n

• 根据 python 日志记录模块文档 - https://docs.python.org/3/library/logging.html#logging.basicConfig，这会向根记录器添加默认的 StreamHandler 。StreamHandler 的默认流是 stderr，这意味着所有日志都会发送到 stderr，并由 Cloud Logging 提取为错误日志。

  \n
\n

\n

为了解决这个问题，我创建了一个 StreamHandler 并指定将 INFO 日志发送到 stdout 而不是 stderr，并使用 addHandler() 方法将此处理程序添加到根记录器。

\n

此后，我遇到的最后一个问题是 GCP 上的重复日志，其中一个具有正确的 INFO 级别，以及具有错误严重性的同一日志的重复项。

\n

原因是日志被传递到 INFO StreamHandler，后者正确地将这些日志写入 stdout，但由于 python 日志记录模块的性质，所有这些日志也被传递到记录器 \xe2\x80\ x9cancestry\xe2\x80\x9d 到根记录器，该记录器将相同的日志写入 stderr，并导致重复。日志记录模块的 python 文档对此进行了解释：

\n

\n
• https://docs.python.org/3/howto/logging.html#logging-flow
\n
• https://docs.python.org/3/library/logging.html#logging.Logger.propagate
\n

\n

解决此问题的方法是将 cloud_logger.propagate 设置为 False，并且不将日志传递给祖先记录器。

\n