Google Cloud Run Jobs 日志记录将多行异常消息拆分为多个日志条目

Question

几天前，我公司的一项 Cloud Run 作业中出现了 Python RuntimeError，导致该错误停止。

不幸的是，Cloud Run 的日志记录以糟糕的方式处理了 RuntimeError。

它正确地将 RuntimeError 堆栈跟踪中的所有行放入第一个日志条目中。

但是具有多行文本（每一行都携带重要诊断信息）的 RuntimeError 消息被毁坏了。该消息的第一行位于包含堆栈跟踪的第一个日志条目中。但剩余的每一行（空白行除外）都被放入其自己的后续日志条目中。

下面是显示该作业的 Google Cloud Run LOGS 选项卡的屏幕截图。在第一个日志条目（顶部的日志条目）中，您可以看到完整的堆栈跟踪以及 RuntimeError 消息的第一行（“捕获一些异常（查看原因）；正在处理...”），但在那之后出现了许多日志条目，它们中的每一个都是 RuntimeError 消息中的单个后续行。屏幕截图仅包含后续行中的前 4 行，第一行是文本“{'broker_order_id': '196056769652',”。

RuntimeError消息处理显然是一场灾难：你必须知道后续行会稍后出现（我首先认为它们根本没有打印），很难阅读它们，它们的日志级别不再是ERROR而是不存在，等等

有谁知道吗

1. 有治愈方法
2. 我们没有正确进行 Cloud Run 日志记录
3. 这是一个已知的错误，或者是我需要向 Google 报告的错误

？

---

在提交这个问题之前，我进行了网络搜索。

我发现很多人报告说，到 2022 年，异常堆栈跟踪都在多行上打印：Python、Java、Java。

但是这些链接中报告的堆栈跟踪多行/多日志条目问题现在似乎已经解决。我报告的问题是，如果您的异常的文本消息（而不是堆栈跟踪）有多行。

---

我的公司在一年前设置了 Cloud Run Jobs 日志记录，当时 Cloud Run Jobs 还处于测试阶段，并且 Cloud Run Jobs 尚未完全支持云日志记录工具。

以缩写形式，我们的 Cloud Run Jobs 日志记录配置类似于下面所示的 Python 代码。

此日志记录配置是否可能已过时并导致此问题？

LOG_FORMAT: str = (
    "%(asctime)s.%(msecs)03dZ "
    "%(levelname)s "
    "%(name)s.%(funcName)s "
    "#%(lineno)d "
    "- "
    "%(message)s"
)

DATE_FORMAT: str = "%Y-%m-%d %H:%M:%S"

_is_logging_configured: bool = False


def get_logger(name: str) -> Logger:
    config_logging()
    
    return getLogger(name)


def config_logging() -> None:
    if _is_logging_configured:
        return
    
    config_gcp_cloud_run_job_logging()
    
    _is_logging_configured = True


def config_gcp_cloud_run_job_logging() -> None:
    root_logger = getLogger()
    root_logger.setLevel(os.environ.get("LOG_LEVEL", "WARNING"))
    formatter = get_logging_formatter()
    
    # get metadata about the execution environment
    region = retrieve_metadata_server(_REGION_ID)
    project = retrieve_metadata_server(_PROJECT_NAME)
    
    # build a manual resource object
    cr_job_resource = Resource(
        type = "cloud_run_job",
        labels = {
            "job_name": os.environ.get("CLOUD_RUN_JOB", "unknownJobId"),
            "location": region.split("/")[-1] if region else "",
            "project_id": project,
        },
    )
    
    # configure library using CloudLoggingHandler with custom resource
    client = Client()
    
    # use labels to assign logs to execution
    labels = {"run.googleapis.com/execution_name": os.environ.get("CLOUD_RUN_EXECUTION", "unknownExecName")}
    
    handler = CloudLoggingHandler(client, resource = cr_job_resource, labels = labels)
    handler.setFormatter(formatter)
    setup_logging(handler)


def get_logging_formatter() -> Formatter:
    formatter = Formatter(fmt = LOG_FORMAT, datefmt = DATE_FORMAT)
    Formatter.converter = time.gmtime
    return formatter

Answer 1

• 这是一个已知错误，已在公共问题跟踪器中向 Google Cloud 报告，目前产品工程团队正在解决此问题，并且没有预计到达时间。这可能是应用程序服务器日志异常分组器未将此堆栈跟踪分组为单个日志行的问题。如果您愿意，可以在该 PIT 链接中添加您的输入或更多详细信息作为评论。不过，如果您觉得需要单独提出请求，则可以使用此 PIT 链接提出请求。

• 为了克服这一问题，您可以使用 Fluent Bit 提供的 “多行”过滤器，它有助于连接最初属于一个上下文但被拆分为多个记录或日志行的消息。常见的示例是堆栈跟踪或以多行打印日志的应用程序。

• 根据 Maxim Ponomarev 的 SO，以避免日志中出现有关同一异常的重复消息。最好记录有关 RuntimeException（或任何其他异常）的消息，以便更容易识别异常并避免重复消息。