使用Google Cloud Stackdriver在Kubernetes Engine上记录Python代码的重复日志条目 [英] Duplicate log entries with Google Cloud Stackdriver logging of Python code on Kubernetes Engine

问题描述

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

I have a simple Python app running in a container on Google Kubernetes Engine. I am trying to connect the standard Python logging to Google Stackdriver logging using this guide. I have almost succeeded, but I am getting duplicate log entries with one always at the 'error' level...

Stackdriver日志的屏幕快照，显示重复的条目

Screenshot of Stackdriver logs showing duplicate entries

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

This is my python code that set's up the logging according to the above guide:

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

以下是触发屏幕截图中的日志的代码:

Here's the code that triggers the logs from the screenshot:

import logging

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

这是完整的Stackdriver日志，是从屏幕快照扩展而成的，其错误级别被错误地解释:

Here is the full Stackdriver log, expanded from the screenshot, with an incorrectly interpreted ERROR level:

{
 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级别:

Here is the the full Stackdriver log, expanded from the screenshot, with a correctly interpreted INFO level:

{
 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"  
}

因此，此条目可能是关键:

So, this entry might be the key:

container.googleapis.com/stream:  "stderr" 

除了我的日志设置工作外，容器中的所有日志都将发送到容器中的stderr，并且我相信默认情况下，至少在Kubernetes Container Engine上，所有stdout/stderr都会被选中是由Google Stackdriver通过FluentD进行的...话虽如此，我目前还不了解.

It looks like in addition to my logging set-up working, all logs from the container are being send to stderr in the container, and I believe that by default, at least on Kubernetes Container Engine, all stdout/stderr are picked up by Google Stackdriver via FluentD... Having said that, I'm out of my depth at this point.

有什么主意为什么要得到这些重复的条目吗?

Any ideas why I am getting these duplicate entries?

推荐答案

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

Problem is in the way how logging client initializes root logger

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

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

it adds default stream handler in addition to Stackdriver handler. My workaround for now is to initialize appropriate Stackdriver handler manually:

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

这篇关于使用Google Cloud Stackdriver在Kubernetes Engine上记录Python代码的重复日志条目的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！