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

Question

我有一个在 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 提供...话虽如此，我现在已经超出了我的理解范围。

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

Answer 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，以添加一个论据以减少这种黑客行为。

Answer 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)