Unverified Commit f26e90f7 authored by mvdbeek's avatar mvdbeek
Browse files

Log start and end of request

Configurable via `use_access_logging_middleware`.
Looks like this:

```
galaxy.webapps.base.api DEBUG 2024-04-23 17:14:43,776 [pN:main,p:73562,tN:MainThread] GET /history/current_history_json?since=2024-04-22T17:24:13.936493 f8c75e2c-30eb-4fcb-9b96-25bd4b2df435
galaxy.webapps.base.api DEBUG 2024-04-23 17:14:48,719 [pN:main,p:73562,tN:MainThread] GET /history/current_history_json?since=2024-04-22T17:24:13.936493 f8c75e2c-30eb-4fcb-9b96-25bd4b2df435 200
galaxy.webapps.base.api DEBUG 2024-04-23 17:14:51,767 [pN:main,p:73562,tN:MainThread] GET /history/current_history_json?since=2024-04-22T17:24:13.936493 2fe6094c-67bb-4144-a19f-cbb4a1b18fb4
galaxy.webapps.base.api DEBUG 2024-04-23 17:14:51,786 [pN:main,p:73562,tN:MainThread] GET /history/current_history_json?since=2024-04-22T17:24:13.936493 2fe6094c-67bb-4144-a19f-cbb4a1b18fb4 200
galaxy.webapps.base.api DEBUG 2024-04-23 17:14:53,139 [pN:main,p:73562,tN:MainThread] GET /api/entry_points?running=true 763693e9-4fd3-4a97-a100-a3c259b4b4c8
```
parent 8f4968f0
Loading
Loading
Loading
Loading
+11 −3
Original line number Diff line number Diff line
@@ -3030,6 +3030,17 @@
:Type: bool


~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
``use_access_logging_middleware``
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

:Description:
    Log request start as well as request end. Disables uvicorn access
    log handler.
:Default: ``false``
:Type: bool


~~~~~~~~~~~~
``use_lint``
~~~~~~~~~~~~
@@ -5477,6 +5488,3 @@
    This requires the help_forum_api_url to be set.
:Default: ``false``
:Type: bool


+4 −0
Original line number Diff line number Diff line
@@ -1743,6 +1743,10 @@ galaxy:
  # job is complete.
  #debug: false

  # Log request start as well as request end. Disables uvicorn access
  # log handler.
  #use_access_logging_middleware: false

  # Check for WSGI compliance.
  #use_lint: false

+7 −0
Original line number Diff line number Diff line
@@ -2193,6 +2193,13 @@ mapping:
          causes the files used by PBS/SGE (submission script, output, and error)
          to remain on disk after the job is complete.

      use_access_logging_middleware:
        type: bool
        default: false
        required: false
        desc: |
          Log request start as well as request end. Disables uvicorn access log handler.

      use_lint:
        type: bool
        default: false
+35 −1
Original line number Diff line number Diff line
import os
import stat
import typing
import uuid
from logging import getLogger

import anyio
from fastapi import (
@@ -15,8 +17,12 @@ from starlette.responses import (
    FileResponse,
    Response,
)
from starlette_context import context
from starlette_context.middleware import RawContextMiddleware
from starlette_context.plugins import RequestIdPlugin
from starlette_context.plugins import (
    Plugin,
    RequestIdPlugin,
)

from galaxy.exceptions import MessageException
from galaxy.exceptions.utils import api_error_to_dict
@@ -32,6 +38,9 @@ if typing.TYPE_CHECKING:
    )


log = getLogger(__name__)


# Copied from https://github.com/tiangolo/fastapi/issues/1240#issuecomment-1055396884
def _get_range_header(range_header: str, file_size: int) -> typing.Tuple[int, int]:
    def _invalid_range():
@@ -192,6 +201,31 @@ def add_exception_handler(app: FastAPI) -> None:
        return get_error_response_for_request(request, exc)


class AccessLoggingMiddleware(Plugin):

    key = "access_line"

    async def process_request(self, request):
        scope = request.scope
        path = scope["root_path"] + scope["path"]
        if scope["query_string"]:
            path = f"{path}?{scope['query_string'].decode('ascii')}"
        access_line = f"{scope['method']} {path} {uuid.uuid4()}"
        log.debug(access_line)
        return access_line

    async def enrich_response(self, response) -> None:
        access_line = context.get("access_line")
        if status := response.get("status"):
            log.debug(f"{access_line} {status}")


def add_raw_context_middlewares(app: FastAPI):
    getLogger("uvicorn.access").handlers = []
    plugins = (RequestIdPlugin(force_new_uuid=True), AccessLoggingMiddleware())
    app.add_middleware(RawContextMiddleware, plugins=plugins)


def add_request_id_middleware(app: FastAPI):
    app.add_middleware(RawContextMiddleware, plugins=(RequestIdPlugin(force_new_uuid=True),))

+5 −1
Original line number Diff line number Diff line
@@ -16,6 +16,7 @@ from galaxy.schema.invocation import CustomJsonSchema
from galaxy.version import VERSION
from galaxy.webapps.base.api import (
    add_exception_handler,
    add_raw_context_middlewares,
    add_request_id_middleware,
    GalaxyFileResponse,
    include_all_package_routers,
@@ -179,6 +180,9 @@ def initialize_fast_app(gx_wsgi_webapp, gx_app):
    app = get_fastapi_instance(root_path=root_path)
    add_exception_handler(app)
    add_galaxy_middleware(app, gx_app)
    if gx_app.config.use_access_logging_middleware:
        add_raw_context_middlewares(app)
    else:
        add_request_id_middleware(app)
    include_all_package_routers(app, "galaxy.webapps.galaxy.api")
    include_legacy_openapi(app, gx_app)