PB-1351 Log requests and errors to ECS

Pipfile

@@ -16,6 +16,7 @@ boto3 = "~=1.35.78"
 nanoid = "~=2.0.0"
 whitenoise = "~=6.8.2"
 pystac-client = "~=0.8.5"
+ecs-logging = "*"
 
 [dev-packages]
 yapf = "*"

app/config/api.py

@@ -1,7 +1,6 @@
-from logging import getLogger
-
 from access.api import router as access_router
 from botocore.exceptions import EndpointConnectionError
+from config.logging import LoggedNinjaAPI
 from distributions.api import router as distributions_router
 from ninja import NinjaAPI
 from ninja.errors import AuthenticationError
@@ -17,9 +16,7 @@
 from django.http import HttpRequest
 from django.http import HttpResponse
 
-logger = getLogger(__name__)
-
-api = NinjaAPI()
+api = LoggedNinjaAPI()
 
 api.add_router("", provider_router)
 api.add_router("", distributions_router)
@@ -32,6 +29,7 @@ def handle_django_validation_error(
 ) -> HttpResponse:
     """Convert the given validation error  to a response with corresponding status."""
     error_code_unique_constraint_violated = "unique"
+
     if contains_error_code(exception, error_code_unique_constraint_violated):
         status = 409
     else:
@@ -61,7 +59,6 @@ def handle_404_not_found(request: HttpRequest, exception: Http404) -> HttpRespon
 
 @api.exception_handler(Exception)
 def handle_exception(request: HttpRequest, exception: Exception) -> HttpResponse:
-    logger.exception(exception)
     return api.create_response(
         request,
         {
@@ -84,7 +81,6 @@ def handle_http_error(request: HttpRequest, exception: HttpError) -> HttpRespons
 
 @api.exception_handler(AuthenticationError)
 def handle_unauthorized(request: HttpRequest, exception: AuthenticationError) -> HttpResponse:
-    logger.exception(exception)
     return api.create_response(
         request,
         {
@@ -101,6 +97,7 @@ def handle_ninja_validation_error(
     messages: list[str] = []
     for error in exception.errors:
         messages.extend(error.values())
+
     return api.create_response(
         request,
         {

app/config/logging-cfg-local.yaml

@@ -0,0 +1,34 @@
+version: 1
+disable_existing_loggers: False
+
+root:
+  handlers:
+    - console
+  level: DEBUG
+  propagate: True
+
+# configure loggers per app
+loggers:
+  django.request:
+    # setting this to ERROR prevents from logging too much
+    # we do the logging ourselves
+    level: ERROR
+#  provider:
+#    level: DEBUG
+#  cognito:
+#    level: DEBUG
+#  access:
+#    level: DEBUG
+#  distributions:
+#    level: DEBUG
+
+formatters:
+  ecs:
+    (): ecs_logging.StdlibFormatter
+
+handlers:
+  console:
+    class: logging.StreamHandler
+    formatter: ecs
+    stream: ext://sys.stdout
+

app/config/logging.py

@@ -0,0 +1,118 @@
+import sys
+from logging import getLogger
+from typing import Any
+from typing import List
+from typing import Optional
+from typing import TypedDict
+
+from ninja import NinjaAPI
+
+from django.conf import settings
+from django.http import HttpRequest
+from django.http import HttpResponse
+
+logger = getLogger(__name__)
+
+LogExtra = TypedDict(
+    'LogExtra',
+    {
+        'http': {
+            'request': {
+                'method': str, 'header': dict[str, str]
+            },
+            'response': {
+                'status_code': int, 'header': dict[str, str]
+            }
+        },
+        'url': {
+            'path': str, 'scheme': str
+        }
+    }
+)
+
+
+def generate_log_extra(request: HttpRequest, response: HttpResponse) -> LogExtra:
+    """Generate the extra dict for the logging calls
+
+    This will format the following extra fields to be sent to the logger:
+
+    request:
+        http:
+            request:
+                method: GET | POST | PUT | ...
+                header: LIST OF HEADERS
+            response:
+                header: LIST OF HEADERS
+                status_code: STATUS_CODE
+
+    url:
+        path: REQUEST_PATH
+        scheme: REQUEST_SCHEME
+
+    Args:
+        request (HttpRequest): Request object
+        response (HttpResponse): Response object
+
+    Returns:
+        dict: dict of extras
+    """
+    return {
+        'http': {
+            'request': {
+                'method': request.method or 'UNKNOWN',
+                'header': {
+                    k.lower(): v for k,
+                    v in request.headers.items() if k.lower() in settings.LOG_ALLOWED_HEADERS
+                }
+            },
+            'response': {
+                'status_code': response.status_code,
+                'header': {
+                    k.lower(): v for k,
+                    v in response.headers.items() if k.lower() in settings.LOG_ALLOWED_HEADERS
+                },
+            }
+        },
+        'url': {
+            'path': request.path or 'UNKNOWN', 'scheme': request.scheme or 'UNKNOWN'
+        }
+    }
+
+
+class LoggedNinjaAPI(NinjaAPI):
+    """Extension for the NinjaAPI to log the requests to elastic
+
+    Overwriting the method that creates a response. The only thing done then
+    is that depending on the status, a log entry will be triggered.
+    """
+
+    def create_response(
+        self,
+        request: HttpRequest,
+        data: Any,
+        *args: List[Any],
+        status: Optional[int] = None,
+        temporal_response: Optional[HttpResponse] = None,
+    ) -> HttpResponse:
+        response = super().create_response(
+            request, data, *args, status=status, temporal_response=temporal_response
+        )
+
+        if response.status_code >= 200 and response.status_code < 400:
+            logger.info(
+                "Response %s on %s",
+                response.status_code,  # parameter for %s
+                request.path,  # parameter for %s
+                extra=generate_log_extra(request, response)
+            )
+        elif response.status_code >= 400 and response.status_code < 500:
+            logger.warning(
+                "Response %s on %s",
+                response.status_code,  # parameter for %s
+                request.path,  # parameter for %s
+                extra=generate_log_extra(request, response)
+            )
+        else:
+            logger.exception(repr(sys.exc_info()[1]), extra=generate_log_extra(request, response))
+
+        return response

app/config/settings_base.py

@@ -10,9 +10,11 @@
 https://docs.djangoproject.com/en/5.0/ref/settings/
 """
 
+import os
 from pathlib import Path
 
 import environ
+import yaml
 
 env = environ.Env()
 
@@ -163,3 +165,71 @@
 # nanoid
 SHORT_ID_SIZE = env.int('SHORT_ID_SIZE', 12)
 SHORT_ID_ALPHABET = env.str('SHORT_ID_ALPHABET', '0123456789abcdefghijklmnopqrstuvwxyz')
+
+
+# Read configuration from file
+def get_logging_config() -> dict[str, object]:
+    '''Read logging configuration
+    Read and parse the yaml logging configuration file passed in the environment variable
+    LOGGING_CFG and return it as dictionary
+    Note: LOGGING_CFG is relative to the root of the repo
+    '''
+    log_config_file = env('LOGGING_CFG', default='config/logging-cfg-local.yaml')
+    if log_config_file.lower() in ['none', '0', '', 'false', 'no']:
+        return {}
+    log_config = {}
+    with open(BASE_DIR / log_config_file, 'rt', encoding="utf-8") as fd:
+        log_config = yaml.safe_load(os.path.expandvars(fd.read()))
+    return log_config
+
+
+LOGGING = get_logging_config()
+
+# list of headers that are allowed to be logged
+_DEFAULT_LOG_ALLOWED_HEADERS = [
+
+    # Standard headers
+    "accept",
+    "accept-encoding",
+    "accept-language",
+    "accept-ranges",
+    "cache-control",
+    "connection",
+    "content-length",
+    "content-security-policy",
+    "content-type",
+    "etag",
+    "host",
+    "if-match",
+    "if-none-match",
+    "origin",
+    "referer",
+    "referrer-policy",
+    "transfer-encoding",
+    "user-agent",
+    "vary",
+    "x-content-type-options",
+    "x-forwarded-for",
+    "x-forwarded-host",
+    "x-forwarded-port",
+    "x-forwarded-proto",
+
+  # Cloudfront headers
+    "cloudfront-is-android-viewer",
+    "cloudfront-is-desktop-viewer",
+    "cloudfront-is-ios-viewer",
+    "cloudfront-is-mobile-viewer",
+    "cloudfront-is-smarttv-viewer",
+    "cloudfront-is-tablet-viewer",
+
+  # PPBGDI headers
+    "x-e2e-testing",
+    # API GW Headers
+    "geoadmin-authenticated"
+    "geoadmin-username",
+    "apigw-requestid"
+]
+LOG_ALLOWED_HEADERS = [
+    str(header).lower()
+    for header in env.list('LOG_ALLOWED_HEADERS', default=_DEFAULT_LOG_ALLOWED_HEADERS)
+]

app/config/settings_prod.py

@@ -1,28 +1,7 @@
-import os
-
-import yaml
-
 from .settings_base import *  # pylint: disable=wildcard-import, unused-wildcard-import
 
 DEBUG = False
 
-
-# Read configuration from file
-def get_logging_config() -> dict[str, object]:
-    '''Read logging configuration
-    Read and parse the yaml logging configuration file passed in the environment variable
-    LOGGING_CFG and return it as dictionary
-    Note: LOGGING_CFG is relative to the root of the repo
-    '''
-    log_config_file = env('LOGGING_CFG', default='app/config/logging-cfg-local.yml')
-    if log_config_file.lower() in ['none', '0', '', 'false', 'no']:
-        return {}
-    log_config = {}
-    with open(BASE_DIR / log_config_file, 'rt', encoding="utf-8") as fd:
-        log_config = yaml.safe_load(os.path.expandvars(fd.read()))
-    return log_config
-
-
 # Static files (CSS, JavaScript, Images)
 # https://docs.djangoproject.com/en/5.0/howto/static-files/