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

Question

我在Google Kubernetes Engine的容器中运行了一个简单的Python应用程序.我正在尝试使用以下指南将标准Python日志记录连接到Google Stackdriver日志记录:https://cloud.google.com/logging/docs/setup/python.我几乎成功了,但我得到了重复的日志条目,其中一个始终处于'错误'级别...

---

显示重复条目的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日志,从屏幕截图中展开,错误解释的ERROR级别:

{
 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容器引擎上,所有stdout/stderr都被Google收集Stackdriver通过FluentD ......话虽如此,我现在已经超出了我的深度.

任何想法为什么我得到这些重复的条目？

Answer 1

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

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。您需要从处理程序列表中删除流处理程序以防止重复。

编辑：我已经向谷歌提交了一个问题，以添加一个参数来减少这个问题。

Answer 2

写于 2022 年，即 v3.0.0google-cloud-logging发布后不久，这个问题也出现在我身上（尽管几乎可以肯定是出于不同的原因）。

调试

我在调试它的过程中做的最有用的事情就是在我的代码中粘贴以下内容：

import logging
...
root_logger = logging.getLogger()  # no arguments = return the root logger
print(root_logger.handlers, flush=True)  # tell me what handlers are attached
...

如果您收到重复的日志，似乎可以肯定这是因为您的记录器附加了多个处理程序，并且 Stackdriver 正在从它们捕获日志！公平地说，这是 Stackdriver 的工作；只是遗憾的是google-cloud-logging默认情况下无法解决这个问题。

好消息是 Stackdriver 还将捕获该print语句（该语句进入 STDOUT 流）。就我而言，记录了以下处理程序列表[<StreamHandler <stderr> (NOTSET)>, <StructuredLogHandler <stderr> (NOTSET)>]：因此：两个处理程序已附加到根记录器。

修复它

您可能会发现您的代码将处理程序附加到其他位置，只需删除该部分即可。但情况可能是这样的，例如依赖项正在设置额外的处理程序，这是我一直在努力解决的问题。

我使用了基于Andy Carlson 所写答案的解决方案。保持通用/可扩展：

import google.cloud.logging
import logging

def is_cloud_handler(handler: logging.Handler) -> bool:
    """
    is_cloud_handler

    Returns True or False depending on whether the input is a
    google-cloud-logging handler class

    """
    accepted_handlers = (
        google.cloud.logging.handlers.StructuredLogHandler,
        google.cloud.logging.handlers.CloudLoggingHandler,
        google.cloud.logging.handlers.ContainerEngineHandler,
        google.cloud.logging.handlers.AppEngineHandler,
    )
    return isinstance(handler, accepted_handlers)


def set_up_logging():
    # here we assume you'll be using the basic logging methods
    # logging.info, logging.warn etc. which invoke the root logger
    client = google.cloud.logging.Client()
    client.setup_logging()

    root_logger = logging.getLogger()
    root_logger.handlers = [h for h in root_logger.handlers if is_cloud_handler(h)]

更多背景信息

对于那些觉得这个解决方案令人困惑的人

在Python中，“记录器”和“处理程序”之间是分开的：记录器生成日志，处理程序决定对它们发生什么。因此，您可以将多个处理程序附加到同一个记录器（如果您希望该记录器的日志发生多种情况）。

该google-cloud-logging库建议您运行其setup_logging方法，然后仅使用内置logging库的基本日志记录方法来创建日志。它们是：logging.debug、logging.info、logging.warning、logging.error和logging.critical（按紧急程度递增的顺序）。

所有logging.Logger实例都具有相同的方法，包括Logger称为根记录器的特殊实例。如果您查看基本日志记录方法的源代码，您会发现它们只是在此根记录器上调用这些方法。

可以设置特定的Loggers，这是划分应用程序不同区域生成的日志的标准做法（而不是通过根记录器发送所有内容）。这是使用logging.getLogger("name-of-logger"). 但是，logging.getLogger()不带参数返回根记录器。

同时，该方法的目的google.cloud.logging.Client.setup_logging是将一个特殊的日志处理程序附加到根记录器。因此，使用logging.info等创建的日志将由处理程序处理google-cloud-logging。但您必须确保没有其他处理程序也附加到根记录器。

幸运的是，Loggers 有一个属性.handlers，它是附加日志处理程序的列表。在此解决方案中，我们只需编辑该列表以确保我们只有一个处理程序。

Answer 3

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

    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)