diff --git a/dashboard/api/Dockerfile b/dashboard/api/Dockerfile index 1f02665f..a26db8e1 100644 --- a/dashboard/api/Dockerfile +++ b/dashboard/api/Dockerfile @@ -36,4 +36,4 @@ EXPOSE 5000 HEALTHCHECK --interval=30s --timeout=3s --start-period=10s --retries=3 \ CMD curl --fail http://localhost:5000/health || exit 1 -CMD ["gunicorn", "--bind", "0.0.0.0:5000", "--workers", "1", "--threads", "2", "--access-logfile", "-", "--error-logfile", "-", "app:create_app()"] +CMD ["gunicorn", "--bind", "0.0.0.0:5000", "--workers", "1", "--threads", "2", "--access-logfile", "-", "--error-logfile", "-", "--logger-class", "gunicorn_logging.HealthCheckFilter", "app:create_app()"] diff --git a/dashboard/api/gunicorn_logging.py b/dashboard/api/gunicorn_logging.py new file mode 100644 index 00000000..61b08a61 --- /dev/null +++ b/dashboard/api/gunicorn_logging.py @@ -0,0 +1,17 @@ +"""Gunicorn logging helpers.""" + +from datetime import timedelta + +from gunicorn.glogging import Logger + + +class HealthCheckFilter(Logger): + """Suppress successful health-check access logs.""" + + def access(self, resp: object, req: object, environ: dict[str, str], request_time: timedelta) -> None: + """Log non-health requests and failed health probes.""" + path = environ.get("PATH_INFO", "").rstrip("/") + status = str(getattr(resp, "status", "")).partition(" ")[0] + if path.endswith("/health") and status == "200": + return + super().access(resp, req, environ, request_time) diff --git a/dashboard/api/tests/unit/test_container_config.py b/dashboard/api/tests/unit/test_container_config.py new file mode 100644 index 00000000..79a31c00 --- /dev/null +++ b/dashboard/api/tests/unit/test_container_config.py @@ -0,0 +1,12 @@ +"""Tests for dashboard API container runtime configuration.""" + +from pathlib import Path + + +def test_gunicorn_suppresses_successful_health_access_logs() -> None: + """Routine successful /health probes should not flood stdout logs.""" + dockerfile = Path(__file__).parents[2] / "Dockerfile" + content = dockerfile.read_text(encoding="utf-8") + + assert "--logger-class" in content + assert "gunicorn_logging.HealthCheckFilter" in content diff --git a/dashboard/auth/Dockerfile b/dashboard/auth/Dockerfile index bb316e79..1d2dce5a 100644 --- a/dashboard/auth/Dockerfile +++ b/dashboard/auth/Dockerfile @@ -27,4 +27,4 @@ EXPOSE 5001 HEALTHCHECK --interval=30s --timeout=3s --start-period=5s --retries=3 \ CMD wget --spider --quiet http://localhost:5001/health || exit 1 -CMD ["gunicorn", "--bind", "0.0.0.0:5001", "--workers", "1", "--access-logfile", "-", "--error-logfile", "-", "auth:app"] +CMD ["gunicorn", "--bind", "0.0.0.0:5001", "--workers", "1", "--access-logfile", "-", "--error-logfile", "-", "--logger-class", "gunicorn_logging.HealthCheckFilter", "auth:app"] diff --git a/dashboard/auth/auth.py b/dashboard/auth/auth.py index b211dd85..374c85d8 100644 --- a/dashboard/auth/auth.py +++ b/dashboard/auth/auth.py @@ -16,7 +16,6 @@ register_error_handlers(app) logger = logging.getLogger(__name__) -_first_health_logged = False # Environment/config @@ -145,10 +144,6 @@ def health() -> tuple[str, int]: Returns: tuple[str, int]: A plain-text OK body and a 200 status code. """ - global _first_health_logged # ruff:ignore[global-statement] - if not _first_health_logged: - logger.info("auth first health response served") - _first_health_logged = True return "OK", HTTPStatus.OK diff --git a/dashboard/auth/gunicorn_logging.py b/dashboard/auth/gunicorn_logging.py new file mode 100644 index 00000000..61b08a61 --- /dev/null +++ b/dashboard/auth/gunicorn_logging.py @@ -0,0 +1,17 @@ +"""Gunicorn logging helpers.""" + +from datetime import timedelta + +from gunicorn.glogging import Logger + + +class HealthCheckFilter(Logger): + """Suppress successful health-check access logs.""" + + def access(self, resp: object, req: object, environ: dict[str, str], request_time: timedelta) -> None: + """Log non-health requests and failed health probes.""" + path = environ.get("PATH_INFO", "").rstrip("/") + status = str(getattr(resp, "status", "")).partition(" ")[0] + if path.endswith("/health") and status == "200": + return + super().access(resp, req, environ, request_time) diff --git a/dashboard/auth/tests/test_auth.py b/dashboard/auth/tests/test_auth.py index 095c2b4b..00113051 100644 --- a/dashboard/auth/tests/test_auth.py +++ b/dashboard/auth/tests/test_auth.py @@ -288,17 +288,3 @@ def test_login_token_requires_token_query_parameter(self, client: FlaskClient) - response = client.get("/login-token") assert response.status_code == HTTPStatus.BAD_REQUEST - - -def test_health_logs_first_health_once(client: FlaskClient, caplog) -> None: - """The first auth health response should be visible in startup diagnostics once.""" - import auth - - auth._first_health_logged = False - caplog.set_level("INFO", logger="auth") - - client.get("/health") - client.get("/health") - - messages = [record.getMessage() for record in caplog.records] - assert messages.count("auth first health response served") == 1 diff --git a/dashboard/auth/tests/test_container_config.py b/dashboard/auth/tests/test_container_config.py new file mode 100644 index 00000000..02f6eb91 --- /dev/null +++ b/dashboard/auth/tests/test_container_config.py @@ -0,0 +1,12 @@ +"""Tests for auth container runtime configuration.""" + +from pathlib import Path + + +def test_gunicorn_suppresses_successful_health_access_logs() -> None: + """Routine successful /health probes should not flood stdout logs.""" + dockerfile = Path(__file__).parents[1] / "Dockerfile" + content = dockerfile.read_text(encoding="utf-8") + + assert "--logger-class" in content + assert "gunicorn_logging.HealthCheckFilter" in content diff --git a/mdrun-api/gunicorn_logging.py b/mdrun-api/gunicorn_logging.py index a2618dbf..61b08a61 100644 --- a/mdrun-api/gunicorn_logging.py +++ b/mdrun-api/gunicorn_logging.py @@ -1,37 +1,17 @@ """Gunicorn logging helpers.""" from datetime import timedelta -from typing import Any from gunicorn.glogging import Logger -HTTP_SUCCESS_MIN = 200 -HTTP_REDIRECT_MIN = 300 - class HealthCheckFilter(Logger): """Suppress successful health-check access logs.""" - def access(self, resp: Any, req: Any, environ: dict[str, Any], request_time: timedelta) -> None: # ruff:ignore[any-type] + def access(self, resp: object, req: object, environ: dict[str, str], request_time: timedelta) -> None: """Log non-health requests and failed health probes.""" - status_code = _get_status_code(resp) - path = environ.get("PATH_INFO", "") - if path == "/api/health" and status_code is not None and HTTP_SUCCESS_MIN <= status_code < HTTP_REDIRECT_MIN: + path = environ.get("PATH_INFO", "").rstrip("/") + status = str(getattr(resp, "status", "")).partition(" ")[0] + if path.endswith("/health") and status == "200": return super().access(resp, req, environ, request_time) - - -def _get_status_code(resp: Any) -> int | None: # ruff:ignore[any-type] - status_int = getattr(resp, "status_int", None) - if isinstance(status_int, int): - return status_int - - status = getattr(resp, "status", None) - if isinstance(status, int): - return status - if isinstance(status, str): - code = status.split(maxsplit=1)[0] - if code.isdigit(): - return int(code) - - return None diff --git a/tuner/api/access_logging.py b/tuner/api/access_logging.py new file mode 100644 index 00000000..59930b34 --- /dev/null +++ b/tuner/api/access_logging.py @@ -0,0 +1,25 @@ +""" +Uvicorn access log filtering. + +The uvicorn access logger emits one record per request as +``logger.info(fmt, (client_addr, method, full_path, http_version, status_code))``; +``AccessFormatter.formatMessage`` unpacks that 5-tuple from ``record.args``. +""" + +import logging + + +class HealthCheckFilter(logging.Filter): + """Suppress successful health-check access logs.""" + + def filter(self, record: logging.LogRecord) -> bool: + """Return False to drop successful health probes; keep all else.""" + args = record.args + if not isinstance(args, tuple): + return True + try: + path = str(args[2]).rstrip("/") + status = str(args[4]) + except IndexError: + return True + return not (path.endswith("/health") and status == "200") diff --git a/tuner/api/start.py b/tuner/api/start.py index a6968216..212ae2dc 100644 --- a/tuner/api/start.py +++ b/tuner/api/start.py @@ -5,6 +5,7 @@ import uvicorn from alembic import command from alembic.config import Config +from uvicorn.config import LOGGING_CONFIG logging.basicConfig( level=logging.INFO, @@ -13,6 +14,10 @@ ) logger = logging.getLogger(__name__) +# Suppress successful health-probe access logs for parity with the gunicorn services. +LOGGING_CONFIG.setdefault("filters", {})["healthcheck"] = {"()": "api.access_logging.HealthCheckFilter"} +LOGGING_CONFIG["loggers"]["uvicorn.access"].setdefault("filters", []).append("healthcheck") + _REQUIRED_ENV = ("TUNER_USER", "TUNER_PASSWORD", "COST_CPU_CORE_HOUR", "COST_GPU_HOUR", "COST_GB_RAM_HOUR") @@ -35,7 +40,7 @@ def main() -> None: from api.main import app # ruff: ignore[import-outside-top-level] — intentional: import after migrations complete try: - uvicorn.run(app, host="0.0.0.0", port=8000) + uvicorn.run(app, host="0.0.0.0", port=8000, log_config=LOGGING_CONFIG) except Exception: logger.exception("Unexpected error while starting.") sys.exit(1) diff --git a/tuner/tests/test_container_config.py b/tuner/tests/test_container_config.py index 6d145284..8394d18f 100644 --- a/tuner/tests/test_container_config.py +++ b/tuner/tests/test_container_config.py @@ -7,3 +7,11 @@ def test_ray_runtime_workdir_excludes_api_virtual_environment() -> None: assert "COPY --chown=app:app tuner/api/ tuner-runtime/api/" in dockerfile assert "RUNTIME_WORKDIR=/app/tuner-runtime" in dockerfile assert 'PYTHONPATH="/app/tuner-runtime"' in dockerfile + + +def test_uvicorn_suppresses_successful_health_access_logs() -> None: + """Routine successful /api/health probes should not flood stdout logs.""" + start_py = (Path(__file__).parents[1] / "api" / "start.py").read_text(encoding="utf-8") + + assert "api.access_logging.HealthCheckFilter" in start_py + assert "log_config=LOGGING_CONFIG" in start_py