From 7d91672e7dc38fed49b3ec6b78dd8be99ebfb5d6 Mon Sep 17 00:00:00 2001 From: Simon Gurcke Date: Thu, 14 Nov 2024 21:53:50 +1000 Subject: [PATCH] WIP --- apitally/client/request_logging.py | 3 +- apitally/django.py | 60 +++++++++++++--- apitally/django_ninja.py | 4 +- apitally/django_rest_framework.py | 4 +- apitally/fastapi.py | 4 +- apitally/flask.py | 50 +++++++++---- apitally/litestar.py | 112 ++++++++++++++++++----------- apitally/starlette.py | 48 +++++++++---- 8 files changed, 196 insertions(+), 89 deletions(-) diff --git a/apitally/client/request_logging.py b/apitally/client/request_logging.py index 4adb318..6954b7a 100644 --- a/apitally/client/request_logging.py +++ b/apitally/client/request_logging.py @@ -39,9 +39,10 @@ class RequestLoggingConfig: class RequestDict(TypedDict): method: str - path: str + path: Optional[str] url: str headers: Dict[str, str] + consumer: Optional[str] class ResponseDict(TypedDict): diff --git a/apitally/django.py b/apitally/django.py index 29b2d8e..194b9b5 100644 --- a/apitally/django.py +++ b/apitally/django.py @@ -16,6 +16,7 @@ from apitally.client.client_threading import ApitallyClient from apitally.client.consumers import Consumer as ApitallyConsumer from apitally.client.logging import get_logger +from apitally.client.request_logging import RequestLoggingConfig from apitally.common import get_versions @@ -24,7 +25,7 @@ from ninja import NinjaAPI -__all__ = ["ApitallyMiddleware", "ApitallyConsumer"] +__all__ = ["ApitallyMiddleware", "ApitallyConsumer", "RequestLoggingConfig"] logger = get_logger(__name__) @@ -32,6 +33,7 @@ class ApitallyMiddlewareConfig: client_id: str env: str + request_logging_config: Optional[RequestLoggingConfig] app_version: Optional[str] identify_consumer_callback: Optional[Callable[[HttpRequest], Union[str, ApitallyConsumer, None]]] urlconfs: List[Optional[str]] @@ -75,6 +77,7 @@ def configure( cls, client_id: str, env: str = "dev", + request_logging_config: Optional[RequestLoggingConfig] = None, app_version: Optional[str] = None, identify_consumer_callback: Optional[str] = None, urlconf: Optional[Union[List[Optional[str]], str]] = None, @@ -82,6 +85,7 @@ def configure( cls.config = ApitallyMiddlewareConfig( client_id=client_id, env=env, + request_logging_config=request_logging_config, app_version=app_version, identify_consumer_callback=import_string(identify_consumer_callback) if identify_consumer_callback @@ -93,15 +97,22 @@ def __call__(self, request: HttpRequest) -> HttpResponse: start_time = time.perf_counter() response = self.get_response(request) response_time = time.perf_counter() - start_time + response_size = ( + _to_int(response["Content-Length"]) + if response.has_header("Content-Length") + else (len(response.content) if not response.streaming else None) + ) path = self.get_path(request) + + try: + consumer = self.get_consumer(request) + consumer_identifier = consumer.identifier if consumer else None + self.client.consumer_registry.add_or_update_consumer(consumer) + except Exception: # pragma: no cover + logger.exception("Failed to get consumer for request") + consumer_identifier = None + if request.method is not None and request.method != "OPTIONS" and path is not None: - try: - consumer = self.get_consumer(request) - consumer_identifier = consumer.identifier if consumer else None - self.client.consumer_registry.add_or_update_consumer(consumer) - except Exception: # pragma: no cover - logger.exception("Failed to get consumer for request") - consumer_identifier = None try: self.client.request_counter.add_request( consumer=consumer_identifier, @@ -110,12 +121,11 @@ def __call__(self, request: HttpRequest) -> HttpResponse: status_code=response.status_code, response_time=response_time, request_size=request.headers.get("Content-Length"), - response_size=response["Content-Length"] - if response.has_header("Content-Length") - else (len(response.content) if not response.streaming else None), + response_size=response_size, ) except Exception: # pragma: no cover logger.exception("Failed to log request metadata") + if ( response.status_code == 422 and (content_type := response.get("Content-Type")) is not None @@ -134,6 +144,7 @@ def __call__(self, request: HttpRequest) -> HttpResponse: ) except Exception: # pragma: no cover logger.exception("Failed to log validation errors") + if response.status_code == 500 and hasattr(request, "unhandled_exception"): try: self.client.server_error_counter.add_server_error( @@ -144,6 +155,24 @@ def __call__(self, request: HttpRequest) -> HttpResponse: ) except Exception: # pragma: no cover logger.exception("Failed to log server error") + + if self.client.request_logger.enabled and request.method is not None: + self.client.request_logger.log_request( + request={ + "method": request.method, + "path": path, + "url": request.build_absolute_uri(), + "headers": dict(request.headers), + "consumer": consumer_identifier, + }, + response={ + "status_code": response.status_code, + "response_time": response_time, + "headers": dict(response.items()), + "size": response_size, + }, + ) + return response def process_exception(self, request: HttpRequest, exception: Exception) -> None: @@ -335,3 +364,12 @@ def _check_import(name: str) -> bool: return True except ImportError: return False + + +def _to_int(x: Union[str, int, None]) -> Optional[int]: + if x is None: + return None + try: + return int(x) + except ValueError: + return None diff --git a/apitally/django_ninja.py b/apitally/django_ninja.py index a3e1a45..30b7a5a 100644 --- a/apitally/django_ninja.py +++ b/apitally/django_ninja.py @@ -1,4 +1,4 @@ -from apitally.django import ApitallyConsumer, ApitallyMiddleware +from apitally.django import ApitallyConsumer, ApitallyMiddleware, RequestLoggingConfig -__all__ = ["ApitallyMiddleware", "ApitallyConsumer"] +__all__ = ["ApitallyMiddleware", "ApitallyConsumer", "RequestLoggingConfig"] diff --git a/apitally/django_rest_framework.py b/apitally/django_rest_framework.py index a3e1a45..30b7a5a 100644 --- a/apitally/django_rest_framework.py +++ b/apitally/django_rest_framework.py @@ -1,4 +1,4 @@ -from apitally.django import ApitallyConsumer, ApitallyMiddleware +from apitally.django import ApitallyConsumer, ApitallyMiddleware, RequestLoggingConfig -__all__ = ["ApitallyMiddleware", "ApitallyConsumer"] +__all__ = ["ApitallyMiddleware", "ApitallyConsumer", "RequestLoggingConfig"] diff --git a/apitally/fastapi.py b/apitally/fastapi.py index c2e8ab7..73743f5 100644 --- a/apitally/fastapi.py +++ b/apitally/fastapi.py @@ -1,4 +1,4 @@ -from apitally.starlette import ApitallyConsumer, ApitallyMiddleware +from apitally.starlette import ApitallyConsumer, ApitallyMiddleware, RequestLoggingConfig -__all__ = ["ApitallyMiddleware", "ApitallyConsumer"] +__all__ = ["ApitallyMiddleware", "ApitallyConsumer", "RequestLoggingConfig"] diff --git a/apitally/flask.py b/apitally/flask.py index 918de24..8b6e99d 100644 --- a/apitally/flask.py +++ b/apitally/flask.py @@ -6,13 +6,14 @@ from warnings import warn from flask import Flask, g -from flask.wrappers import Response +from flask.wrappers import Request, Response from werkzeug.datastructures import Headers from werkzeug.exceptions import NotFound from werkzeug.test import Client from apitally.client.client_threading import ApitallyClient from apitally.client.consumers import Consumer as ApitallyConsumer +from apitally.client.request_logging import RequestLoggingConfig from apitally.common import get_versions @@ -21,7 +22,7 @@ from werkzeug.routing.map import Map -__all__ = ["ApitallyMiddleware", "ApitallyConsumer"] +__all__ = ["ApitallyMiddleware", "ApitallyConsumer", "RequestLoggingConfig"] class ApitallyMiddleware: @@ -30,13 +31,14 @@ def __init__( app: Flask, client_id: str, env: str = "dev", + request_logging_config: Optional[RequestLoggingConfig] = None, app_version: Optional[str] = None, openapi_url: Optional[str] = None, ) -> None: self.app = app self.wsgi_app = app.wsgi_app self.patch_handle_exception() - self.client = ApitallyClient(client_id=client_id, env=env) + self.client = ApitallyClient(client_id=client_id, env=env, request_logging_config=request_logging_config) self.client.start_sync_loop() self.delayed_set_startup_data(app_version, openapi_url) @@ -90,36 +92,56 @@ def add_request( response_time: float, response_headers: Headers, ) -> None: - rule, is_handled_path = self.get_rule(environ) - if is_handled_path and environ["REQUEST_METHOD"] != "OPTIONS": + path = self.get_path(environ) + request = Request(environ, populate_request=False, shallow=True) + response_size = response_headers.get("Content-Length", type=int) + + if path is not None and request.method != "OPTIONS": consumer = self.get_consumer() consumer_identifier = consumer.identifier if consumer else None self.client.consumer_registry.add_or_update_consumer(consumer) self.client.request_counter.add_request( consumer=consumer_identifier, - method=environ["REQUEST_METHOD"], - path=rule, + method=request.method, + path=path, status_code=status_code, response_time=response_time, - request_size=environ.get("CONTENT_LENGTH"), - response_size=response_headers.get("Content-Length", type=int), + request_size=request.content_length, + response_size=response_size, ) if status_code == 500 and "unhandled_exception" in g: self.client.server_error_counter.add_server_error( consumer=consumer_identifier, - method=environ["REQUEST_METHOD"], - path=rule, + method=request.method, + path=path, exception=g.unhandled_exception, ) - def get_rule(self, environ: WSGIEnvironment) -> Tuple[str, bool]: + if self.client.request_logger.enabled: + self.client.request_logger.log_request( + request={ + "method": request.method, + "path": path, + "url": request.url, + "headers": dict(request.headers), + "consumer": consumer_identifier, + }, + response={ + "status_code": status_code, + "response_time": response_time, + "headers": dict(response_headers), + "size": response_size, + }, + ) + + def get_path(self, environ: WSGIEnvironment) -> Optional[str]: url_adapter = self.app.url_map.bind_to_environ(environ) try: endpoint, _ = url_adapter.match() rule = self.app.url_map._rules_by_endpoint[endpoint][0] - return rule.rule, True + return rule.rule except NotFound: - return environ["PATH_INFO"], False + return None def get_consumer(self) -> Optional[ApitallyConsumer]: if "apitally_consumer" in g and g.apitally_consumer: diff --git a/apitally/litestar.py b/apitally/litestar.py index 1f0c09b..2f7ff21 100644 --- a/apitally/litestar.py +++ b/apitally/litestar.py @@ -15,10 +15,11 @@ from apitally.client.client_asyncio import ApitallyClient from apitally.client.consumers import Consumer as ApitallyConsumer +from apitally.client.request_logging import RequestLoggingConfig from apitally.common import get_versions -__all__ = ["ApitallyPlugin", "ApitallyConsumer"] +__all__ = ["ApitallyPlugin", "ApitallyConsumer", "RequestLoggingConfig"] class ApitallyPlugin(InitPluginProtocol): @@ -26,11 +27,12 @@ def __init__( self, client_id: str, env: str = "dev", + request_logging_config: Optional[RequestLoggingConfig] = None, app_version: Optional[str] = None, filter_openapi_paths: bool = True, identify_consumer_callback: Optional[Callable[[Request], Union[str, ApitallyConsumer, None]]] = None, ) -> None: - self.client = ApitallyClient(client_id=client_id, env=env) + self.client = ApitallyClient(client_id=client_id, env=env, request_logging_config=request_logging_config) self.app_version = app_version self.filter_openapi_paths = filter_openapi_paths self.identify_consumer_callback = identify_consumer_callback @@ -122,57 +124,81 @@ def add_request( response_body: bytes, response_size: int = 0, ) -> None: - if response_status < 100 or not request.route_handler.paths: + if response_status < 100: return # pragma: no cover path = self.get_path(request) - if path is None or self.filter_path(path): + if self.filter_path(path): return + consumer = self.get_consumer(request) consumer_identifier = consumer.identifier if consumer else None self.client.consumer_registry.add_or_update_consumer(consumer) - self.client.request_counter.add_request( - consumer=consumer_identifier, - method=request.method, - path=path, - status_code=response_status, - response_time=response_time, - request_size=request.headers.get("Content-Length"), - response_size=response_size or response_headers.get("Content-Length"), - ) - if response_status == 400 and response_body and len(response_body) < 4096: - with contextlib.suppress(json.JSONDecodeError): - parsed_body = json.loads(response_body) - if ( - isinstance(parsed_body, dict) - and "detail" in parsed_body - and isinstance(parsed_body["detail"], str) - and "validation" in parsed_body["detail"].lower() - and "extra" in parsed_body - and isinstance(parsed_body["extra"], list) - ): - self.client.validation_error_counter.add_validation_errors( - consumer=consumer_identifier, - method=request.method, - path=path, - detail=[ - { - "loc": [error.get("source", "body")] + error["key"].split("."), - "msg": error["message"], - "type": "", - } - for error in parsed_body["extra"] - if "key" in error and "message" in error - ], - ) - if response_status == 500 and "exception" in request.state: - self.client.server_error_counter.add_server_error( + + if path is not None: + self.client.request_counter.add_request( consumer=consumer_identifier, method=request.method, path=path, - exception=request.state["exception"], + status_code=response_status, + response_time=response_time, + request_size=request.headers.get("Content-Length"), + response_size=response_size or response_headers.get("Content-Length"), + ) + + if response_status == 400 and response_body and len(response_body) < 4096: + with contextlib.suppress(json.JSONDecodeError): + parsed_body = json.loads(response_body) + if ( + isinstance(parsed_body, dict) + and "detail" in parsed_body + and isinstance(parsed_body["detail"], str) + and "validation" in parsed_body["detail"].lower() + and "extra" in parsed_body + and isinstance(parsed_body["extra"], list) + ): + self.client.validation_error_counter.add_validation_errors( + consumer=consumer_identifier, + method=request.method, + path=path, + detail=[ + { + "loc": [error.get("source", "body")] + error["key"].split("."), + "msg": error["message"], + "type": "", + } + for error in parsed_body["extra"] + if "key" in error and "message" in error + ], + ) + + if response_status == 500 and "exception" in request.state: + self.client.server_error_counter.add_server_error( + consumer=consumer_identifier, + method=request.method, + path=path, + exception=request.state["exception"], + ) + + if self.client.request_logger.enabled: + self.client.request_logger.log_request( + request={ + "method": request.method, + "path": path, + "url": str(request.url), + "headers": dict(request.headers), + "consumer": consumer_identifier, + }, + response={ + "status_code": response_status, + "response_time": response_time, + "headers": dict(response_headers), + "size": response_size, + }, ) def get_path(self, request: Request) -> Optional[str]: + if not request.route_handler.paths: + return None path: List[str] = [] for layer in request.route_handler.ownership_layers: if isinstance(layer, HTTPRouteHandler): @@ -183,8 +209,8 @@ def get_path(self, request: Request) -> Optional[str]: path.append(layer.path.lstrip("/")) return "/" + "/".join(filter(None, path)) - def filter_path(self, path: str) -> bool: - if self.filter_openapi_paths and self.openapi_path: + def filter_path(self, path: Optional[str]) -> bool: + if path is not None and self.filter_openapi_paths and self.openapi_path: return path == self.openapi_path or path.startswith(self.openapi_path + "/") return False # pragma: no cover diff --git a/apitally/starlette.py b/apitally/starlette.py index 0c3462e..d549179 100644 --- a/apitally/starlette.py +++ b/apitally/starlette.py @@ -4,7 +4,7 @@ import contextlib import json import time -from typing import Any, Callable, Dict, List, Optional, Tuple, Union +from typing import Any, Callable, Dict, List, Optional, Union from warnings import warn from httpx import HTTPStatusError @@ -17,10 +17,11 @@ from apitally.client.client_asyncio import ApitallyClient from apitally.client.consumers import Consumer as ApitallyConsumer +from apitally.client.request_logging import RequestLoggingConfig from apitally.common import get_versions -__all__ = ["ApitallyMiddleware", "ApitallyConsumer"] +__all__ = ["ApitallyMiddleware", "ApitallyConsumer", "RequestLoggingConfig"] class ApitallyMiddleware: @@ -29,13 +30,14 @@ def __init__( app: ASGIApp, client_id: str, env: str = "dev", + request_logging_config: Optional[RequestLoggingConfig] = None, app_version: Optional[str] = None, openapi_url: Optional[str] = "/openapi.json", identify_consumer_callback: Optional[Callable[[Request], Union[str, ApitallyConsumer, None]]] = None, ) -> None: self.app = app self.identify_consumer_callback = identify_consumer_callback - self.client = ApitallyClient(client_id=client_id, env=env) + self.client = ApitallyClient(client_id=client_id, env=env, request_logging_config=request_logging_config) self.client.start_sync_loop() self._delayed_set_startup_data_task: Optional[asyncio.Task] = None self.delayed_set_startup_data(app_version, openapi_url) @@ -118,17 +120,18 @@ def add_request( response_size: int = 0, exception: Optional[BaseException] = None, ) -> None: - path_template, is_handled_path = self.get_path_template(request) - if is_handled_path: - consumer = self.get_consumer(request) - consumer_identifier = consumer.identifier if consumer else None - self.client.consumer_registry.add_or_update_consumer(consumer) + path = self.get_path(request) + consumer = self.get_consumer(request) + consumer_identifier = consumer.identifier if consumer else None + self.client.consumer_registry.add_or_update_consumer(consumer) + + if path is not None: if response_status == 0 and exception is not None: response_status = 500 self.client.request_counter.add_request( consumer=consumer_identifier, method=request.method, - path=path_template, + path=path, status_code=response_status, response_time=response_time, request_size=request.headers.get("Content-Length"), @@ -142,24 +145,41 @@ def add_request( self.client.validation_error_counter.add_validation_errors( consumer=consumer_identifier, method=request.method, - path=path_template, + path=path, detail=body["detail"], ) if response_status == 500 and exception is not None: self.client.server_error_counter.add_server_error( consumer=consumer_identifier, method=request.method, - path=path_template, + path=path, exception=exception, ) + if self.client.request_logger.enabled: + self.client.request_logger.log_request( + request={ + "method": request.method, + "path": path, + "url": str(request.url), + "headers": dict(request.headers), + "consumer": consumer_identifier, + }, + response={ + "status_code": response_status, + "response_time": response_time, + "headers": dict(response_headers), + "size": response_size, + }, + ) + @staticmethod - def get_path_template(request: Request) -> Tuple[str, bool]: + def get_path(request: Request) -> Optional[str]: for route in request.app.routes: match, _ = route.matches(request.scope) if match == Match.FULL: - return route.path, True - return request.url.path, False + return route.path + return None def get_consumer(self, request: Request) -> Optional[ApitallyConsumer]: if hasattr(request.state, "apitally_consumer") and request.state.apitally_consumer: