Improve error handling and logging

src/ddns_service/server.py

@@ -2,7 +2,6 @@
 
 from __future__ import annotations
 
-import argon2
 import base64
 import ipaddress
 import json
@@ -32,6 +31,7 @@ from .models import (
     get_hostname_for_user,
     get_user
 )
+from argon2.exceptions import VerifyMismatchError
 from concurrent.futures import ThreadPoolExecutor
 from http.server import BaseHTTPRequestHandler, ThreadingHTTPServer
 from urllib.parse import parse_qs, urlparse
@@ -138,6 +138,25 @@ class DDNSServer(ThreadingHTTPServer):
         super().server_close()
 
 
+class DDNSError(Exception):
+    def __init__(self, message, code, status, client_ip, username=None, hostname=None):
+        super().__init__(self, message)
+        self.message = message
+        self.code = code
+        self.status = status
+        self.client_ip = client_ip
+        self.username = username
+        self.hostname = hostname
+
+    def __str__(self):
+        string = f"{self.message}: client={self.client_ip}"
+        if self.username:
+            string += f" username={self.username}"
+        if self.hostname:
+            string += f" hostname={self.hostname}"
+        return string
+
+
 class DDNSRequestHandler(BaseHTTPRequestHandler):
     """HTTP request handler for DDNS updates."""
 
@@ -217,21 +236,11 @@ class DDNSRequestHandler(BaseHTTPRequestHandler):
     def do_GET(self):
         """Handle GET requests."""
         set_txn_id()
-        try:
-            self._handle_get_request()
-        except Exception as e:
-            logging.exception(f"Uncaught exception: {e}")
-            self.respond(500, "Internal Server Error")
-        finally:
-            clear_txn_id()
-
-    def _handle_get_request(self):
-        """Handle GET request logic."""
         try:
             client_ip = self.get_client_ip()
         except ProxyHeaderError as e:
             logging.error(f"Proxy header error: {e}")
-            self.send_response_body(400, "Bad Request")
+            self.respond(400, "Bad Request")
             return
 
         # Bad rate limit check
@@ -244,13 +253,31 @@ class DDNSRequestHandler(BaseHTTPRequestHandler):
                 self.respond(429, STATUS_ABUSE)
                 return
 
+        try:
+            self._handle_get_request(client_ip)
+        except DDNSError as e:
+            if self.app.bad_limiter:
+                self.app.bad_limiter.record(client_ip)
+            logging.warning(e)
+            self.respond(e.code, e.status)
+        except DatabaseError as e:
+            logging.error(f"Database error: {e}")
+            self.respond(500, "Internal Server Error")
+        except Exception as e:
+            logging.exception(f"Uncaught exception: {e}")
+            self.respond(500, "Internal Server Error")
+        finally:
+            clear_txn_id()
+
+    def _handle_get_request(self, client_ip):
+        """Handle GET request logic."""
         # Parse URL
         parsed = urlparse(self.path)
 
         # Find matching endpoint
         endpoint = self.app.config["_endpoint_map"].get(parsed.path)
         if endpoint is None:
-            self.send_response_body(404, "Not Found")
+            self.respond(404, "Not Found")
             return
 
         # Parse query parameters
@@ -263,48 +290,29 @@ class DDNSRequestHandler(BaseHTTPRequestHandler):
             password = extract_param(params, endpoint["params"]["password"])
 
         if not username or not password:
-            logging.warning(f"Auth failed: client={client_ip} user=anonymous")
+            raise DDNSError(
-            self._handle_bad_request(client_ip, 401, STATUS_BADAUTH)
+                "Auth failed",
-            return
+                401,
-
+                STATUS_BADAUTH,
-        # Validate credentials
+                client_ip
-        try:
+            )
-            try:
-                user = get_user(username)
-                self.app.password_hasher.verify(user.password_hash, password)
-            except (DoesNotExist, argon2.exceptions.VerifyMismatchError):
-                logging.warning(f"Auth failed: client={client_ip} user={username}")
-                self._handle_bad_request(client_ip, 401, STATUS_BADAUTH)
-                return
 
         # Get hostname parameter
         hostname_param = extract_param(params, endpoint["params"]["hostname"])
         if not hostname_param:
-                logging.warning(f"Missing hostname: client={client_ip} user={username}")
+            raise DDNSError(
-                self._handle_bad_request(client_ip, 400, STATUS_NOHOST)
+                "Missing hostname",
-                return
+                400,
+                STATUS_NOHOST,
+                client_ip,
+                username
+            )
+
+        # Validate credentials
+        user = self._authenticate(client_ip, username, password)
 
         # Check hostname ownership
-            try:
+        hostname = self._check_permissions(client_ip, hostname_param, user)
-                hostname = get_hostname_for_user(hostname_param, user)
-            except DoesNotExist:
-                logging.warning(
-                    f"Access denied: client={client_ip} user={username} "
-                    f"hostname={hostname_param}"
-                )
-                self._handle_bad_request(client_ip, 403, STATUS_NOHOST)
-                return
-            except EncodingError:
-                logging.warning(
-                    f"Invalid hostname: client={client_ip}, "
-                    f"hostname={hostname_param}")
-                self._handle_bad_request(client_ip, 400, STATUS_NOHOST)
-                return
-
-        except DatabaseError as e:
-            logging.error(f"Database error: {e}")
-            self.respond(500, "Internal Server Error")
-            return
 
         # Good rate limit check
         if self.app.good_limiter:
@@ -320,23 +328,67 @@ class DDNSRequestHandler(BaseHTTPRequestHandler):
         if self.app.good_limiter:
             self.app.good_limiter.record(client_ip)
 
-        # Determine IPs to update
+        # get myip, myip6 and notify_change parameters
-        result = self._process_ip_update(hostname, params, endpoint, client_ip)
-        if result:
-            code, status, kwargs = result
-            self.respond(code, status, **kwargs)
-
-    def _handle_bad_request(self, client_ip, code, status):
-        """Handle bad request and record in rate limiter."""
-        if self.app.bad_limiter:
-            self.app.bad_limiter.record(client_ip)
-        self.respond(code, status)
-
-    def _process_ip_update(self, hostname, params, endpoint, client_ip):
-        """Process IP update for hostname."""
         myip = extract_param(params, endpoint["params"]["ipv4"])
         myip6 = extract_param(params, endpoint["params"]["ipv6"])
+        notify_change = extract_param(params, endpoint["params"]["notify_change"])
 
+        # Process update request
+        code, status, kwargs = self._process_ip_update(
+            hostname,
+            client_ip,
+            myip,
+            myip6,
+            notify_change
+        )
+        self.respond(code, status, **kwargs)
+
+    def _authenticate(self, client_ip, username, password):
+        try:
+            try:
+                user = get_user(username)
+            except DoesNotExist:
+                # User does not exist, Hash fake password to prevent time-based attacks
+                self.app.password_hasher.hash("FAKE-PASSWORD")
+                raise DoesNotExist
+
+            self.app.password_hasher.verify(user.password_hash, password)
+        except (DoesNotExist, VerifyMismatchError):
+            raise DDNSError(
+                "Auth failed",
+                401,
+                STATUS_BADAUTH,
+                client_ip,
+                username
+            )
+
+        return user
+
+    def _check_permissions(self, client_ip, hostname_param, user):
+        # Check hostname ownership
+        code = None
+
+        try:
+            hostname = get_hostname_for_user(hostname_param, user)
+        except DoesNotExist:
+            code = 403
+        except EncodingError:
+            code = 400
+
+        if code:
+            raise DDNSError(
+                "Access denied",
+                code,
+                STATUS_NOHOST,
+                client_ip,
+                user.username,
+                hostname_param
+            )
+
+        return hostname
+
+    def _process_ip_update(self, hostname, client_ip, myip, myip6, notify_change):
+        """Process IP update for hostname."""
         ipv4 = None
         ipv6 = None
 
@@ -422,16 +474,15 @@ class DDNSRequestHandler(BaseHTTPRequestHandler):
         # Update database
         hostname.save()
 
-        notify_change_val = extract_param(params, endpoint["params"]["notify_change"])
-        notify_change = notify_change_val.lower() not in ["0", "n", "no", "off"] \
-            if notify_change_val else False
-
         changed_addrs = ""
         if ipv4_changed:
             changed_addrs += f" ipv4={ipv4}"
         if ipv6_changed:
             changed_addrs += f" ipv6={ipv6}"
 
+        notify_change = notify_change.lower() in ["1", "y", "yes", "on", "true"] \
+            if notify_change else False
+
         if not ipv4_changed and not ipv6_changed:
             logging.info(
                 f"No change: client={client_ip} hostname={hostname.hostname} "