diff --git a/simplyblock_core/utils/__init__.py b/simplyblock_core/utils/__init__.py index 65c23abb7..eceb26e0c 100644 --- a/simplyblock_core/utils/__init__.py +++ b/simplyblock_core/utils/__init__.py @@ -1,4 +1,5 @@ # coding=utf-8 +import contextvars import glob import json import logging @@ -12,6 +13,14 @@ import sys import uuid import time + +request_id_var: contextvars.ContextVar[str] = contextvars.ContextVar('request_id', default='-') + + +class RequestIdFilter(logging.Filter): + def filter(self, record): + record.request_id = request_id_var.get() + return True from datetime import datetime, timezone from typing import Union, Any, Optional, Tuple, List, Dict, Iterable from docker import DockerClient @@ -646,7 +655,8 @@ def get_logger(name=""): if not logg.hasHandlers(): logger_handler = logging.StreamHandler(stream=sys.stdout) - logger_handler.setFormatter(logging.Formatter('%(asctime)s: %(thread)d: %(levelname)s: %(message)s')) + logger_handler.addFilter(RequestIdFilter()) + logger_handler.setFormatter(logging.Formatter('%(asctime)s: %(thread)d: [%(request_id)s] %(levelname)s: %(message)s')) logg.addHandler(logger_handler) # gelf_handler = GELFTCPHandler('0.0.0.0', constants.GELF_PORT) # logg.addHandler(gelf_handler) diff --git a/simplyblock_web/app.py b/simplyblock_web/app.py index 2cf9fd214..5cf6b832a 100644 --- a/simplyblock_web/app.py +++ b/simplyblock_web/app.py @@ -5,6 +5,7 @@ import ssl import sys import time +import uuid from fastapi import FastAPI, Request from fastapi.middleware.wsgi import WSGIMiddleware @@ -23,8 +24,9 @@ access_logger = logging.getLogger('simplyblock_web.access') _access_handler = logging.StreamHandler(stream=sys.stdout) +_access_handler.addFilter(core_utils.RequestIdFilter()) _access_handler.setFormatter(logging.Formatter( - '%(asctime)s %(levelname)s %(client_ip)s' + '%(asctime)s %(levelname)s [%(request_id)s] %(client_ip)s' ' "%(message)s" %(status_code)s %(request_size)s %(response_size)s %(duration_ms).2fms "%(user_agent)s"' )) access_logger.addHandler(_access_handler) @@ -39,13 +41,21 @@ async def dispatch(self, request: Request, call_next): client_ip = request.client.host if request.client else '-' user_agent = request.headers.get('user-agent', '-') request_size = request.headers.get('content-length', '-') + request_id = request.headers.get('x-request-id') or uuid.uuid4().hex[:8] + token = core_utils.request_id_var.set(request_id) path = request.url.path if request.url.query: path = f'{path}?{request.url.query}' start = time.monotonic() - response = await call_next(request) + try: + response = await call_next(request) + except Exception: + logger.exception('Unhandled exception during %s %s (%.1fms)', + request.method, path, (time.monotonic() - start) * 1000) + core_utils.request_id_var.reset(token) + raise duration_ms = (time.monotonic() - start) * 1000 response_size = response.headers.get('content-length', '-') @@ -63,6 +73,7 @@ async def dispatch(self, request: Request, call_next): 'duration_ms': duration_ms, }, ) + core_utils.request_id_var.reset(token) return response