Google Cloud logging, Python3.8 standard environment, group request related logs by trace id

Question

I stucked with problem during Google Cloud Logging setup for Python3.8 in Google App Engine Standard environment. I'm using FastAPI with unicorn. My code logging configuration:

import logging.config
import sys

from google.cloud import logging as google_logging

from app.settings import ENV, _settings


if _settings.ENV == ENV.LOCAL:
    MAIN_LOGGER = 'console'
    LOGGER_CONF_DICT = {
        'class': 'logging.StreamHandler',
        'formatter': 'verbose',
        'stream': sys.stdout,
        'level': _settings.LOG_LEVEL.upper(),
    }
else:
    log_client = google_logging.Client()
    MAIN_LOGGER = 'stackdriver_logging'
    LOGGER_CONF_DICT = {
        'class': 'app.gcloud_logs.GCLHandler',
        'client': log_client,
        'name': 'appengine.googleapis.com%2Frequest_log'
        # I've tried other names: stdout, %2FA instead of / symbol, appengine.googleapis.com/stdout
        # the same result or no logs at all
    }

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'verbose': {
            'format': '%(log_color)s%(asctime)s [%(levelname)s] [%(name)s] %(message)s (%(filename)s:%(lineno)d)',
            '()': 'colorlog.ColoredFormatter',
            'log_colors': {
                'DEBUG': 'cyan',
                'INFO': 'green',
                'WARNING': 'yellow',
                'ERROR': 'red',
                'CRITICAL': 'bold_red',
            },
        }
    },
    'handlers': {
        MAIN_LOGGER: {**LOGGER_CONF_DICT},
        'blackhole': {'level': 'DEBUG', 'class': 'logging.NullHandler'},
    },
    'loggers': {
        'fastapi': {'level': 'INFO', 'handlers': [MAIN_LOGGER]},
        'uvicorn.error': {'level': 'INFO', 'handlers': [MAIN_LOGGER], 'propagate': False},
        'uvicorn.access': {'level': 'INFO', 'handlers': [MAIN_LOGGER], 'propagate': False},
        'uvicorn': {'level': 'INFO', 'handlers': [MAIN_LOGGER], 'propagate': False},
        'google.cloud.logging.handlers.transports.background_thread': {'level': 'DEBUG', 'handlers': ['blackhole'],
                                                                       'propagate': False},
        '': {
            'level': _settings.LOG_LEVEL.upper(),
            'handlers': [MAIN_LOGGER],
            'propagate': True,
        },

    }
}

logging.config.dictConfig(LOGGING)

And my logging handler code:

import os
from typing import Any, Dict, Optional

from google.cloud.logging.handlers import CloudLoggingHandler
from google.cloud.logging.resource import Resource
from starlette.requests import Request
from starlette_context import context

from app.settings import _settings


class GCLHandler(CloudLoggingHandler):
    def emit(self, record):
        message = super(GCLHandler, self).format(record)
        request: Optional[Request] = None
        trace: Optional[str] = None
        span_id: Optional[str] = None
        user_id: Optional[int] = None
        resource = Resource(
            type='gae_app',
            labels={
                'module_id': os.environ['GAE_SERVICE'],
                'project_id': _settings.PROJECT_NAME,
                'version_id': os.environ['GAE_VERSION'],
                'zone': 'us16'  # tried without zone - the same result
            }
        )

        labels: Dict[str, Any] = {}

        if context.exists():  # I'm sure that it works
            request = context.get('request')  # I'm sure that it works
            user_id = context.get('user_id')  # I'm sure that it works

        if user_id is not None:
            labels['user_id'] = user_id

        if request:
            if request.headers.get('X-Cloud-Trace-Context'):
                cloud_trace = request.headers.get('X-Cloud-Trace-Context').split('/')
                if len(cloud_trace) > 1:
                    span_id = cloud_trace[1].split(';')[0]

                trace = f'projects/{_settings.PROJECT_NAME}/traces/{cloud_trace[0]}'
                labels['logging.googleapis.com/trace'] = cloud_trace[0]  # Found in some guides, not sure that its neccessary
                labels['appengine.googleapis.com/trace_id'] = cloud_trace[0]  # Found in some guides, not sure that its neccessary

        self.transport.send(
            record,
            message,
            resource=resource,
            labels=labels,
            trace=trace,
            span_id=span_id
        )

I've got some strange results in logs viewer that my log has the same trace as request log, but they're not grouped

Any ideas?

Answer 1

log_client = google_logging.Client()
MAIN_LOGGER = 'stackdriver_logging'
LOGGER_CONF_DICT = {
    'class': 'app.gcloud_logs.GCLHandler',
    'client': log_client,
    'name': 'app'
}

Change name to app is helped