Make Python logging Work in GCP

Table of Contents

When deploying a Python application to GCP Kuberntes Engine, we may see issues that the logging level is not correct in the cloud logging explorer. In order for the Python logging package to work with GCP, we need some additional configurations.

structured logging
#

The GCP logging is using structured logging. The logging message from the Python default logging library is not structured. That is why we are using the google cloud logging client to reformat the logging messages. We can find the structure for the logEntry used by google cloud logging here.

ref:

structured logging: https://cloud.google.com/logging/docs/structured-logging#use-api

Using the gcloud logging client
#

Install the GCP logging client for Python is simple:

pip install --upgrade google-cloud-logging

The google-cloud-logging package will transform the log message to a format required by the Gcloud logging platform. It will work under the hood to make sure the log severity level is correct and also add other fields to the log message.

The official instruction from here tells us to do the following:

root_logger = logging.getLogger()
root_logger.setLevel(LOG_LEVEL)

gcloud_log_client = google.cloud.logging.Client()
gcloud_log_client.setup_logging(log_level=logging.DEBUG)

And in your actual code, you do something like this:

import logging

logger = logging.getLogger(__name__)

logger.info("this is an info message")

The setup_logging() method will add a custom handler from the gcloud logging package, so that the messages from the Python logging package is transformed to a format required by google cloud logging. When the application is running in (GKE), the following handler is added to the root logger

google.cloud.logging_v2.handlers.structured_log.StructuredLogHandler

When the application is running locally, the following handler is added to the root logger:

google.cloud.logging_v2.handlers.handlers.CloudLoggingHandler

The difference between CloudLoggingHandler and StructuredLogHandler can be found here.

However, this plain way has several potential issues:

The log message is not going be printed in the console, if you are developing the code locally
If you also add other handlers to the root logger, you will see duplicated logging messages in the GCP cloud logging explorer¹.
You need to run gcloud auth application-default login to autenticate yourself when running the application locally.

Separate logging setup for local and GCP
#

It is better to have separate setup for the root logger when running the code locally². Something like this should suffice:

import logging
import google.cloud.logging

root_logger = logging.getLogger()
root_logger.setLevel(LOG_LEVEL)

formatter = logging.Formatter("%(name)s:%(lineno)d - %(levelname)s - %(message)s")

# running_in_gcp_k8s() check whether the code is running in GCP kubernetes engine (GKE)
if running_in_gcp_k8s():
    gcloud_log_client = google.cloud.logging.Client()
    gcloud_log_client.setup_logging(log_level=logging.DEBUG)
else:
    # for local running, use a plain stream handler
    stream_handler = logging.StreamHandler()
    stream_handler.setLevel(LOG_LEVEL)
    stream_handler.setFormatter(formatter)

    # add stream handler to root_logger
    root_logger.addHandler(stream_handler)

formatter for gcloud logging handler?
#

By default, if you use the setup_logging() method above, only the plain message is printed. If we want to include logRecord attributes like module name, line number, level name etc, we need to define our own formatter.

import logging
import google.cloud.logging_v2

gcloud_log_client = google.cloud.logging.Client()
gcloud_log_client.setup_logging(log_level=logging.DEBUG)

formatter = logging.Formatter("%(name)s:%(lineno)d - %(levelname)s - %(message)s")
gcp_handler = [for h in logging.getLogger().handlers if isinstance(h, google.cloud.logging_v2.handlers.StructuredLogHandler)][0]
gcp_handler.setFormatter(formatter)

log extra field
#

With cloud logging, we can also log extra meta data, like trace, labels etc.

logger.info(
    "logging test, info level with extra field",
    extra={"json_fields": {"key": "value"}, "trace": "1234", "labels": {"foo": "bar"}},
)