From f2ffe394ad2743c596c88eca5c46a1fafc235d97 Mon Sep 17 00:00:00 2001 From: Florian Date: Sat, 18 Oct 2025 20:59:50 +0200 Subject: [PATCH] Unified log levels - Logger doesn't start with log level DEBUG by default, instead reads a environment variable - Secret handler raises exceptions instead of using the module os to exit - Added extensive debug logging - Notifications: Added timestamp and category --- README.md | 90 ++++++++++++++++++++++++++++++++++- src/db.py | 15 +++++- src/dockerhub_api.py | 66 +++++++++++++++++++------ src/github_api.py | 20 +++++--- src/logger_handler.py | 8 +++- src/main.py | 58 +++++++++++++++------- src/secret_handler.py | 13 +++-- src/send_notification.py | 39 +++++++++------ src/uvicorn_logging_config.py | 39 --------------- 9 files changed, 249 insertions(+), 99 deletions(-) delete mode 100644 src/uvicorn_logging_config.py diff --git a/README.md b/README.md index fdfb3b4..2f93e66 100644 --- a/README.md +++ b/README.md @@ -1,4 +1,90 @@ -# docker-repository-query +# Docker Repository Query Service +A FastAPI-based service that monitors Docker repositories (Docker Hub and GitHub Container Registry) for new image versions and sends notifications when updates are detected. -FastAPI service with endpoints that check for updated versions of two applications so far, Suwayomi and Pi-hole. \ No newline at end of file +## Features + +- **Multi-Registry Support**: Queries both Docker Hub and GitHub Container Registry (GHCR) +- **Version Tracking**: Maintains local state of latest known versions in MySQL +- **Automatic Notifications**: Sends alerts when new versions are detected +- **Prometheus Metrics**: Built-in request monitoring +- **Scheduled Queries**: Designed to be called by external schedulers (cron, Kubernetes CronJob, etc.) + +## Use Case + +This service is ideal for: +- Monitoring self-hosted applications for updates +- Automating update notifications for Docker-based infrastructure +- Tracking specific image tags across different registries + +## Prerequisites + +- Python 3.8+ +- MySQL database +- Required Python packages (see Installation) + +## Installation + +```bash +pip install -r requirements.txt +``` + +## Running the Application + +```bash +python main.py +``` + +This starts two servers: +- **Main API**: `http://0.0.0.0:5000` +- **Metrics Server**: `http://0.0.0.0:9000` + +## API Endpoints + +### Health Check +``` +GET /health +``` +Returns 200 status code if the service is running. + +### Check Suwayomi Updates +``` +GET /suwayomi +``` + +Queries GitHub Container Registry for the latest stable version of Suwayomi/Tachidesk. + +**Response:** +- `200 OK`: New version detected and notification sent +- `204 No Content`: No new version available +- `500 Internal Server Error`: Query or database error + +**Registry:** GitHub Container Registry (ghcr.io) +**Repository:** Suwayomi/tachidesk +**Tag:** stable + +### Check Pi-hole Updates +``` +GET /pihole +``` + +Queries Docker Hub for the latest version of Pi-hole. + +**Response:** +- `200 OK`: New version detected and notification sent +- `204 No Content`: No new version available +- `500 Internal Server Error`: Query or database error + +**Registry:** Docker Hub +**Repository:** pihole/pihole +**Tag:** latest + +## Monitoring + +### Prometheus Metrics + +Prometheus metrics are exposed on port 9000 and include: +- HTTP request counters by method, path, and status code +- Success/failure rates for version checks + +Access metrics at: `http://0.0.0.0:9000/metrics` \ No newline at end of file diff --git a/src/db.py b/src/db.py index 653ed8d..fa6b16e 100644 --- a/src/db.py +++ b/src/db.py @@ -1,4 +1,3 @@ -import mysql.connector from mysql.connector import pooling, Error import threading from secret_handler import return_credentials @@ -34,6 +33,7 @@ def create_connection_pool(): global _connection_pool with _pool_lock: if _connection_pool is not None: + logger.debug("[MySQL] Pool already exists, returning existing pool") return for attempt in range (1,MAX_RETRIES+1): try: @@ -52,6 +52,7 @@ def create_connection_pool(): except Error as e: logger.warning(f"[MySQL] Attempt {attempt} failed: {e}") if attempt < MAX_RETRIES: + logger.debug(f"[MySQL] Retrying in {RETRY_DELAY} seconds...") time.sleep(RETRY_DELAY) logger.critical(f"[MySQL] Failed to connect after {MAX_RETRIES} attempts.") @@ -61,34 +62,43 @@ def close_connection_pool(): global _connection_pool with _pool_lock: if _connection_pool: + logger.debug(f"[MySQL] Closing pool: {_connection_pool}") _connection_pool = None logger.info("[MySQL] Connection pool closed") _stop_healthcheck.set() + logger.debug("[MySQL] Healthcheck stop flag set") def get_connection_pool(): global _connection_pool with _pool_lock: if _connection_pool is None: + logger.debug("[MySQL] No pool found, creating one") create_connection_pool() + else: + logger.debug(f"[MySQL] Returning existing pool: {_connection_pool}") return _connection_pool def get_db(): pool = get_connection_pool() + logger.debug(f"[MySQL] Acquiring connection from pool: {pool}") conn = pool.get_connection() try: conn.ping(reconnect=True, attempts=3, delay=1) + logger.debug("[MySQL] Connection alive") except Error as e: logger.warning(f"[MySQL] Connection dead, recreating pool: {e}") create_connection_pool() pool = get_connection_pool() conn = pool.get_connection() + logger.debug("[MySQL] Reconnected successfully") try: yield conn finally: if conn and conn.is_connected(): conn.close() + logger.debug("[MySQL] Connection returned to pool") def _pool_healthcheck(): while not _stop_healthcheck.is_set(): @@ -96,11 +106,13 @@ def _pool_healthcheck(): with _pool_lock: pool = _connection_pool if not pool: + logger.debug("[MySQL] Healthcheck skipped, pool not initialized") continue try: conn = pool.get_connection() conn.ping(reconnect=True, attempts=3, delay=1) conn.close() + logger.debug(f"[MySQL] Pool healthcheck succeeded") except Error as e: logger.warning(f"[MySQL] Pool healthcheck failed: {e}") create_connection_pool() @@ -109,6 +121,7 @@ def _pool_healthcheck(): def start_healthcheck_thread(): global _health_thread if _health_thread and _health_thread.is_alive(): + logger.debug("[MySQL] Healthcheck thread already running") return _stop_healthcheck.clear() _health_thread = threading.Thread(target=_pool_healthcheck, daemon=True) diff --git a/src/dockerhub_api.py b/src/dockerhub_api.py index 86747e0..ab80ca4 100644 --- a/src/dockerhub_api.py +++ b/src/dockerhub_api.py @@ -1,29 +1,67 @@ import requests from secret_handler import return_credentials +from logger_handler import setup_logger dockerhub_token = return_credentials("/etc/secrets/dockerhub_token") dockerhub_username = return_credentials("/etc/secrets/dockerhub_username") +logger = setup_logger(__name__) -def login_and_get_token()->str: +def login_and_get_token() -> str: """ - You have to first login with credentials to get a token for subsequent api requests. + [DockerHub] Login to Docker Hub and retrieve a JWT token. + + Returns: + A string JWT token for authenticated requests. + Returns None and logs error if login fails. """ login_url = "https://hub.docker.com/v2/users/login/" - response = requests.post(login_url, - json={"username": dockerhub_username, "password": dockerhub_token}) - if response.status_code == 200: - token = response.json()["token"] - return token - else: - print(f"Login failed: {response.status_code} - {response.text}") + response = requests.post( + login_url, + json={"username": dockerhub_username, "password": dockerhub_token} + ) -def find_package_version_with_tag(repo, tag): + if response.status_code == 200: + token = response.json().get("token") + if token: + logger.debug("[DockerHub] Login successful, token obtained") + return token + else: + logger.error("[DockerHub] Login response did not contain token") + return None + else: + logger.error(f"[DockerHub] Login failed: {response.status_code} - {response.text}") + return None + + +def find_package_version_with_tag(repo: str, tag: str) -> str: + """ + [DockerHub] Fetch the tag ID for a repository tag. + + Authenticates with Docker Hub, queries the repository for the tag, + returns the tag ID if found, else None. + """ token = login_and_get_token() + if not token: + logger.error(f"[DockerHub] Cannot fetch tag '{tag}' for repo '{repo}' without token") + return None + headers = {"Authorization": f"JWT {token}"} tags_url = f"https://hub.docker.com/v2/repositories/{repo}/tags/{tag}?page_size=1" - tags_response = requests.get(tags_url, headers=headers) - id = tags_response.json()["id"] - return id - + + response = requests.get(tags_url, headers=headers) + if response.status_code != 200: + logger.error(f"[DockerHub] Failed to fetch tag '{tag}' for repo '{repo}': {response.status_code} - {response.text}") + return None + + data = response.json() + tag_id = data.get("id") + if tag_id: + logger.info(f"[DockerHub] Found tag '{tag}' for repo '{repo}', ID: {tag_id}") + return tag_id + else: + logger.debug(f"[DockerHub] Tag '{tag}' not found for repo '{repo}'") + return None + + if __name__ == "__main__": print(find_package_version_with_tag("pihole/pihole", "latest")) \ No newline at end of file diff --git a/src/github_api.py b/src/github_api.py index a7d44ee..03c7f85 100644 --- a/src/github_api.py +++ b/src/github_api.py @@ -1,12 +1,16 @@ import requests from secret_handler import return_credentials +from logger_handler import setup_logger github_token = return_credentials("/etc/secrets/github_token") +logger = setup_logger(__name__) -def find_package_version_with_tag(org:str,package:str,target_tag:str)->str: +def find_package_version_with_tag(org: str, package: str, target_tag: str) -> str: """ - Iterates through the available pages looking for the supplied target_tag - Either returns None or a string when successful + [GitHub] Search for a container package version with the specified tag. + + Iterates through GitHub Package Registry pages for a given org and package, + returns the version ID matching the target_tag, or None if not found. """ headers = { "Authorization": f"Bearer {github_token}", @@ -22,21 +26,23 @@ def find_package_version_with_tag(org:str,package:str,target_tag:str)->str: response = requests.get(url, headers=headers, params=params) if response.status_code != 200: - print(f"Error {response.status_code}: {response.text}") + logger.error(f"[GitHub] Error {response.status_code} fetching {package}: {response.text}") return None versions = response.json() if not versions: - print(f"Reached end of pages — tag '{target_tag}' not found.") + logger.debug(f"[GitHub] Reached end of pages — tag '{target_tag}' not found for {package}.") return None for version in versions: tags = version.get("metadata", {}).get("container", {}).get("tags", []) if target_tag in tags: - print(f"Found tag '{target_tag}' on page {page}:\n") + logger.info(f"[GitHub] Found tag '{target_tag}' for {package} on page {page}, version ID: {version['id']}") return version["id"] page += 1 - + logger.debug(f"[GitHub] Tag '{target_tag}' not found on page {page-1}, moving to page {page}") + + if __name__ == "__main__": find_package_version_with_tag("Suwayomi", "tachidesk", "stable") \ No newline at end of file diff --git a/src/logger_handler.py b/src/logger_handler.py index 25c121d..3911736 100644 --- a/src/logger_handler.py +++ b/src/logger_handler.py @@ -1,4 +1,9 @@ import logging +import os + +LOG_LEVEL = os.getenv("LOG_LEVEL", "INFO").upper() +if LOG_LEVEL not in {"ERROR", "DEBUG", "INFO", "WARNING", "CRITICAL"}: + LOG_LEVEL = "INFO" def setup_logger(name: str) -> logging.Logger: logger = logging.getLogger(name) @@ -9,5 +14,6 @@ def setup_logger(name: str) -> logging.Logger: ) handler.setFormatter(formatter) logger.addHandler(handler) - logger.setLevel(logging.DEBUG) + logger.setLevel(getattr(logging, LOG_LEVEL)) + logger.debug(f"Logger {name} initialized with level {LOG_LEVEL}") return logger diff --git a/src/main.py b/src/main.py index 6a9c0fc..aa8a5a5 100644 --- a/src/main.py +++ b/src/main.py @@ -5,26 +5,29 @@ from dockerhub_api import find_package_version_with_tag as find_package_version_ import uvicorn from contextlib import asynccontextmanager from db import get_db, create_connection_pool, close_connection_pool, start_healthcheck_thread -import logging +from logger_handler import setup_logger, LOG_LEVEL from send_notification import send_notification from metrics_server import REQUEST_COUNTER import asyncio -logger = logging.getLogger(__name__) +logger = setup_logger(__name__) + @asynccontextmanager async def lifespan(app: FastAPI): - logger.info("Starting application...") + logger.info("[App] Starting application...") - logger.info("Creating MySQL connection pool...") + logger.info("[DB] Creating MySQL connection pool...") create_connection_pool() start_healthcheck_thread() - logger.info("MySQL healthcheck thread started.") + logger.info("[DB] MySQL healthcheck thread started.") yield - logger.info("Closing MySQL connection pool...") + logger.info("[App] Closing MySQL connection pool...") close_connection_pool() + logger.info("[App] Shutdown complete.") + api = FastAPI( title="Docker Repository Query", @@ -35,17 +38,22 @@ api = FastAPI( @api.middleware("http") async def prometheus_middleware(request: Request, call_next): + logger.debug(f"[Metrics] Incoming request: {request.method} {request.url.path}") + status = 500 try: response = await call_next(request) status = response.status_code + logger.debug(f"[Metrics] Request processed with status {status}") except Exception: - status = 500 + logger.error(f"[Metrics] Exception occurred: {e}", exc_info=True) raise finally: REQUEST_COUNTER.labels(request.method, request.url.path, status).inc() + logger.debug(f"[Metrics] Counter incremented for {request.method} {request.url.path} [{status}]") return response + @api.get("/health") def return_health(): return Response(status_code=200) @@ -58,22 +66,30 @@ def handle_suwayomi( ): try: - logger.info("Suwayomi handler invoked") + logger.info("[App] Suwayomi handler invoked") latest_online_version = find_package_version_with_tag_github("Suwayomi", "tachidesk", "stable") + logger.debug(f"[App] Fetched latest Suwayomi version from GitHub: {latest_online_version}") cursor = db.cursor() cursor.execute("SELECT latest_version FROM docker_repositories WHERE app='suwayomi'") local_state = cursor.fetchone() + logger.debug(f"[App] Local Suwayomi version from DB: {local_state}") if local_state and latest_online_version != local_state[0]: + logger.debug("[App] Version mismatch detected. Updating database.") cursor.execute ("UPDATE docker_repositories SET latest_version=%s WHERE app='suwayomi'", - (latest_online_version,)) + (latest_online_version,)) db.commit() - logger.info("New Suwayomi version has been found") + logger.info("[App] New Suwayomi version recorded in database") send_notification("New Suwayomi version has been found") + logger.debug("[App] Notification sent for Suwayomi update") return Response(status_code=200) + + logger.debug("[App] No new Suwayomi version found") return Response(status_code=204) + except Exception as e: + logger.error(f"[App] Error in Suwayomi handler: {e}", exc_info=True) raise HTTPException(status_code=500, detail=str(e)) @@ -84,33 +100,43 @@ def handle_pihole( db = Depends(get_db) ): try: - logger.info("Pi-hole handler invoked") + logger.info("[App] Pi-hole handler invoked") latest_online_version = find_package_version_with_tag_dockerhub("pihole/pihole", "latest") - + logger.debug(f"Fetched latest Pi-hole version from Docker Hub: {latest_online_version}") + cursor = db.cursor() cursor.execute("SELECT latest_version FROM docker_repositories WHERE app='pihole'") local_state = cursor.fetchone() + logger.debug(f"[App] Local Pi-hole version from DB: {local_state}") if local_state and latest_online_version != local_state[0]: + logger.debug("[App] Version mismatch detected. Updating database.") cursor.execute ("UPDATE docker_repositories SET latest_version=%s WHERE app='pihole'", (latest_online_version,)) db.commit() - logger.info("New Pi-hole version has been found") + logger.info("[App] New Pi-hole version recorded in database") send_notification("New Pi-hole version has been found") + logger.debug("[App] Notification sent for Pi-hole update") return Response(status_code=200) + + logger.debug("[App] No new Pi-hole version found") return Response(status_code=204) + except Exception as e: + logger.error(f"[App] Error in Pi-hole handler: {e}", exc_info=True) raise HTTPException(status_code=500, detail=str(e)) async def start_servers(): - config_main = uvicorn.Config("main:api", host="0.0.0.0", port=5000, log_level="info") - config_metrics = uvicorn.Config("metrics_server:metrics_api", host="0.0.0.0", port=9000, log_level="info") + logger.info("Starting main and metrics servers") + config_main = uvicorn.Config("main:api", host="0.0.0.0", port=5000, log_level=LOG_LEVEL.lower()) + config_metrics = uvicorn.Config("metrics_server:metrics_api", host="0.0.0.0", port=9000, log_level=LOG_LEVEL.lower()) server_main = uvicorn.Server(config_main) server_metrics = uvicorn.Server(config_metrics) - + logger.debug("Launching servers concurrently") await asyncio.gather(server_main.serve(), server_metrics.serve()) + logger.info("Both servers have stopped") if __name__ == "__main__": asyncio.run(start_servers()) diff --git a/src/secret_handler.py b/src/secret_handler.py index 33d66a5..639a2a1 100644 --- a/src/secret_handler.py +++ b/src/secret_handler.py @@ -1,12 +1,15 @@ -import sys +from logger_handler import setup_logger + +logger = setup_logger(__name__) def return_credentials(path: str)->str: + logger.debug(f"[Secrets] Opening file:{path}") try: with open (path) as file: return file.read().strip() except FileNotFoundError: - print(f"[FATAL] Secret file not found: {path}") - sys.exit(1) + logger.fatal(f"[FATAL] Secret file not found: {path}") + raise except Exception as e: - print(f"[FATAL] Failed to read secret file {path}: {e}") - sys.exit(1) + logger.fatal(f"[FATAL] Failed to read secret file {path}: {e}") + raise diff --git a/src/send_notification.py b/src/send_notification.py index 3dcca28..64fee6d 100644 --- a/src/send_notification.py +++ b/src/send_notification.py @@ -12,10 +12,14 @@ api_key= return_credentials("/etc/secrets/api_key") logger = setup_logger(__name__) -def send_notification(notification:str, - max_retries: int = 5, - timeout: int = 5 - )->str: +def send_notification(notification:str,max_retries: int = 5,timeout: int = 5)->str: + """ + Sends a notification to the internal backend service when a new docker image is released. + + Parameters: + notification: Name of the docker repository. + """ + headers = { "X-API-Key-Internal": api_key, "Content-Type": "application/json" @@ -26,28 +30,35 @@ def send_notification(notification:str, "message": { "title": notification, "info": "A new version is available.", - "link": None + "link": None, + "category":"utility", + "timestamp": int(time.time()) }} + logger.debug(f"[Notify] Preparing to send notification: title='{notification}'") + with requests.Session() as session: - for attempt in range(1,max_retries+1): + for attempt in range(1, max_retries + 1): try: + logger.debug(f"[Notify] Sending request to backend (attempt {attempt}/{max_retries})") response = session.post(backend_api_url, headers=headers, json=data, timeout=timeout) response.raise_for_status() - logger.info("Notification sent successfully") + logger.info(f"[Notify] Notification sent successfully for '{notification}'") return response.text - except (Timeout,ConnectionError) as e: - logger.warning(f"Attempt {attempt}/{max_retries} failed: {type(e).__name__}") + except (Timeout, ConnectionError) as e: + logger.warning(f"[Notify] Attempt {attempt}/{max_retries} failed: {type(e).__name__}") if attempt == max_retries: + logger.error(f"[Notify] All retry attempts failed for '{notification}'") raise HTTPException(status_code=503, detail=f"Notification service unavailable: {type(e).__name__}") - time.sleep(2 ** (attempt - 1)) + sleep_time = 2 ** (attempt - 1) + logger.debug(f"[Notify] Retrying in {sleep_time} seconds...") + time.sleep(sleep_time) except HTTPError as e: - logger.error(f"HTTP {e.response.status_code}: {e.response.text}") + logger.error(f"[Notify] HTTP {e.response.status_code}: {e.response.text}") raise HTTPException(status_code=e.response.status_code, detail=e.response.text) - + except RequestException as e: - logger.error(f"Unexpected request failure: {e}") + logger.error(f"[Notify] Unexpected request failure: {e}") raise HTTPException(status_code=500, detail=f"Request failed: {str(e)}") - return "" \ No newline at end of file diff --git a/src/uvicorn_logging_config.py b/src/uvicorn_logging_config.py deleted file mode 100644 index a2854db..0000000 --- a/src/uvicorn_logging_config.py +++ /dev/null @@ -1,39 +0,0 @@ -LOGGING_CONFIG = { - "version": 1, - "disable_existing_loggers": False, - "formatters": { - "default": { - "format": "%(asctime)s - %(levelname)s - %(name)s - %(message)s", - "datefmt": "%Y-%m-%d %H:%M:%S", - } - }, - "handlers": { - "default": { - "class": "logging.StreamHandler", - "formatter": "default", - "stream": "ext://sys.stdout" - } - }, - "loggers": { - "": { # root logger - "handlers": ["default"], - "level": "INFO", - "propagate": False - }, - "uvicorn": { - "handlers": ["default"], - "level": "INFO", - "propagate": False - }, - "uvicorn.error": { - "handlers": ["default"], - "level": "INFO", - "propagate": False - }, - "uvicorn.access": { - "handlers": ["default"], - "level": "INFO", - "propagate": False - } - } -}