在 Kubernetes Engine 上使用 Google Cloud Stackdriver 记录 Python 代码的重复日志条目

Posted 2023-02-23

【中文标题】在 Kubernetes Engine 上使用 Google Cloud Stackdriver 记录 Python 代码的重复日志条目

【英文标题】：Duplicate log entries with Google Cloud Stackdriver logging of Python code on Kubernetes Engine

【发布时间】：2018-06-13 04:01:08

【问题描述】：

我有一个在 Google Kubernetes Engine 上的容器中运行的简单 Python 应用。我正在尝试将标准 Python 日志记录连接到 Google Stackdriver 日志记录 using this guide。我几乎成功了，但是我得到了重复的日志条目，其中一个始终处于“错误”级别...

---

显示重复条目的 Stackdriver 日志屏幕截图

这是我根据上述指南设置日志记录的 python 代码：

import webapp2
from paste import httpserver
import rpc

# Imports the Google Cloud client library
import google.cloud.logging
# Instantiates a client
client = google.cloud.logging.Client()
# Connects the logger to the root logging handler; by default this captures
# all logs at INFO level and higher
client.setup_logging()

app = webapp2.WSGIApplication([('/rpc/([A-Za-z]+)', rpc.RpcHandler),], debug=True)
httpserver.serve(app, host='0.0.0.0', port='80')

这是从屏幕截图中触发日志的代码：

import logging

logging.info("INFO Entering PostEchoPost...")
logging.warning("WARNING Entering PostEchoPost...")
logging.error("ERROR Entering PostEchoPost...")
logging.critical("CRITICAL Entering PostEchoPost...")

以下是完整的 Stackdriver 日志，从屏幕截图扩展而来，错误级别解释不正确：

 insertId:  "1mk4fkaga4m63w1"  
 labels: 
  compute.googleapis.com/resource_name:  "gke-alg-microservice-default-pool-xxxxxxxxxx-ttnz"   
  container.googleapis.com/namespace_name:  "default"   
  container.googleapis.com/pod_name:  "esp-alg-xxxxxxxxxx-xj2p2"   
  container.googleapis.com/stream:  "stderr"   
 
 logName:  "projects/projectname/logs/algorithm"  
 receiveTimestamp:  "2018-01-03T12:18:22.479058645Z"  
 resource: 
  labels: 
   cluster_name:  "alg-microservice"    
   container_name:  "alg"    
   instance_id:  "703849119xxxxxxxxxx"   
   namespace_id:  "default"    
   pod_id:  "esp-alg-xxxxxxxxxx-xj2p2"    
   project_id:  "projectname"    
   zone:  "europe-west1-b"    
  
  type:  "container"   
 
 severity:  "ERROR"  
 textPayload:  "INFO Entering PostEchoPost...
"  
 timestamp:  "2018-01-03T12:18:20Z"  

以下是完整的 Stackdriver 日志，从屏幕截图扩展而来，包含正确解释的 INFO 级别：

 insertId:  "1mk4fkaga4m63w0"  
 jsonPayload: 
  message:  "INFO Entering PostEchoPost..."   
  thread:  140348659595008   
 
 labels: 
  compute.googleapis.com/resource_name:  "gke-alg-microservi-default-pool-xxxxxxxxxx-ttnz"   
  container.googleapis.com/namespace_name:  "default"   
  container.googleapis.com/pod_name:  "esp-alg-xxxxxxxxxx-xj2p2"   
  container.googleapis.com/stream:  "stderr"   
 
 logName:  "projects/projectname/logs/algorithm"  
 receiveTimestamp:  "2018-01-03T12:18:22.479058645Z"  
 resource: 
  labels: 
   cluster_name:  "alg-microservice"    
   container_name:  "alg"    
   instance_id:  "703849119xxxxxxxxxx"    
   namespace_id:  "default"    
   pod_id:  "esp-alg-xxxxxxxxxx-xj2p2"    
   project_id:  "projectname"    
   zone:  "europe-west1-b"    
  
  type:  "container"   
 
 severity:  "INFO"  
 timestamp:  "2018-01-03T12:18:20.260099887Z"  

所以，这个条目可能是关键：

container.googleapis.com/stream:  "stderr" 

看起来除了我的日志设置工作之外，来自容器的所有日志都被发送到容器中的 stderr，我相信默认情况下，至少在 Kubernetes Container Engine 上，所有 stdout/stderr 都被选中由 Google Stackdriver 通过 FluentD 提供...话虽如此，我现在已经超出了我的理解范围。

知道为什么我会收到这些重复的条目吗？

【问题讨论】：

链接到的文档指出：“注意：写入 stdout 和 stderr 的日志会自动发送到 Stackdriver Logging，而无需使用 Python 的 Stackdriver Logging 库。”这意味着您需要的信息已经存在。如注释文本所示，您无需使用 Stackdriver Logging 库，并生成带有重复信息的额外日志。

@George 如果只有默认日志记录到 Cloud Logging 没有写出错误的日志级别，例如 WARN as ERROR。

我也有同样的问题。我使用下面链接的本指南来正确设置消息的严重性，但我也得到了一组严重性更高的重复项：medium.com/retailmenot-engineering/…

【参考方案1】：

我通过在调用setup_logging 方法后立即覆盖我的根记录器上的handlers 属性解决了这个问题

import logging
from google.cloud import logging as gcp_logging
from google.cloud.logging.handlers import CloudLoggingHandler, ContainerEngineHandler, AppEngineHandler

logging_client = gcp_logging.Client()
logging_client.setup_logging(log_level=logging.INFO)
root_logger = logging.getLogger()
# use the GCP handler ONLY in order to prevent logs from getting written to STDERR
root_logger.handlers = [handler
                        for handler in root_logger.handlers
                        if isinstance(handler, (CloudLoggingHandler, ContainerEngineHandler, AppEngineHandler))]

为了详细说明这一点，client.setup_logging 方法设置了 2 个处理程序，一个普通的logging.StreamHandler 和一个 GCP 特定的处理程序。因此，日志将同时发送到 stderr 和 Cloud Logging。您需要从处理程序列表中删除流处理程序以防止重复。

编辑： 我已向 Google 提交了issue，以添加一个论据以减少这种黑客行为。

【讨论】：

提醒其他人在使用 Google Cloud Functions 而不是 k8s 时遇到类似问题。删除流处理程序似乎根本不会导致任何日志。

【参考方案2】：

问题在于日志记录客户端如何初始化根记录器

    logger = logging.getLogger()
    logger.setLevel(log_level)
    logger.addHandler(handler)
    logger.addHandler(logging.StreamHandler())

除了 Stackdriver 处理程序之外，它还添加了默认流处理程序。 我现在的解决方法是手动初始化适当的 Stackdriver 处理程序：

            # this basically manually sets logger compatible with GKE/fluentd
            # as LoggingClient automatically add another StreamHandler - so 
            # log records are duplicated
            from google.cloud.logging.handlers import ContainerEngineHandler
            formatter = logging.Formatter("%(message)s")
            handler = ContainerEngineHandler(stream=sys.stderr)
            handler.setFormatter(formatter)
            handler.setLevel(level)
            root = logging.getLogger()
            root.addHandler(handler)
            root.setLevel(level)