Pre-warm DNS for endpoint latency

Change-Id: I9c8db07791446ffea7d8a5467cc1ebbcf8b65b71

Author: benfogel

app/check_http_endpoints.py

@@ -6,6 +6,8 @@
 from pydantic import BaseModel, Field
 from typing import List
 from prometheus_client import Counter, Histogram
+import socket
+from urllib.parse import urlparse
 
 log = logging.getLogger('check.http_endpoints')
 
@@ -22,7 +24,7 @@
 HTTP_ENDPOINT_LATENCY_SECONDS = Histogram(
     'http_endpoint_latency_seconds',
     'Latency of HTTP endpoint checks in seconds',
-    ['endpoint_name']
+    ['endpoint_name', 'status']
 )
 
 class Endpoint(BaseModel):
@@ -48,20 +50,31 @@ def is_healthy(self):
         return True
 
     def check_endpoint(self, endpoint: Endpoint):
+        # Pre-resolve DNS to warm up the cache for timing purposes.
+        try:
+            parsed_url = urlparse(endpoint.url)
+            hostname = parsed_url.hostname
+            port = parsed_url.port or {'http': 80, 'https': 443}.get(parsed_url.scheme, 80)
+            if hostname:
+                socket.getaddrinfo(hostname, port)
+        except (socket.gaierror, TypeError) as e:
+            # Log the pre-resolution failure, but proceed. The actual request will handle the error.
+            log.warning(f"DNS pre-resolution failed for {hostname}: {e}")
+
         start_time = time.time()
         try:
             response = requests.request(endpoint.method, endpoint.url, timeout=endpoint.timeout)
             if not response.ok:
                 log.error(f"HTTP endpoint {endpoint.name} ({endpoint.url}) returned status code {response.status_code}")
                 HTTP_ENDPOINT_FAILURE_TOTAL.labels(endpoint_name=endpoint.name).inc()
+                HTTP_ENDPOINT_LATENCY_SECONDS.labels(endpoint_name=endpoint.name, status='failure').observe(response.elapsed.total_seconds())
                 return False
         except requests.exceptions.RequestException as e:
             log.error(f"Failed to connect to HTTP endpoint {endpoint.name} ({endpoint.url}): {e}")
             HTTP_ENDPOINT_FAILURE_TOTAL.labels(endpoint_name=endpoint.name).inc()
+            HTTP_ENDPOINT_LATENCY_SECONDS.labels(endpoint_name=endpoint.name, status='failure').observe(time.time() - start_time)
             return False
-        finally:
-            latency = time.time() - start_time
-            HTTP_ENDPOINT_LATENCY_SECONDS.labels(endpoint_name=endpoint.name).observe(latency)
 
         HTTP_ENDPOINT_SUCCESS_TOTAL.labels(endpoint_name=endpoint.name).inc()
+        HTTP_ENDPOINT_LATENCY_SECONDS.labels(endpoint_name=endpoint.name, status='success').observe(response.elapsed.total_seconds())
         return True

app/test_check_http_endpoints.py

@@ -26,7 +26,7 @@ def test_check_endpoint_success(self, mock_success, mock_failure, mock_latency,
         mock_success.labels.assert_called_once_with(endpoint_name='example')
         mock_success.labels.return_value.inc.assert_called_once()
         mock_failure.labels.assert_not_called()
-        mock_latency.labels.assert_called_once_with(endpoint_name='example')
+        mock_latency.labels.assert_called_once_with(endpoint_name='example', status='success')
         mock_latency.labels.return_value.observe.assert_called_once()
 
     @patch('check_http_endpoints.requests.request')
@@ -48,7 +48,7 @@ def test_check_endpoint_http_error(self, mock_success, mock_failure, mock_latenc
         mock_failure.labels.assert_called_once_with(endpoint_name='example')
         mock_failure.labels.return_value.inc.assert_called_once()
         mock_success.labels.assert_not_called()
-        mock_latency.labels.assert_called_once_with(endpoint_name='example')
+        mock_latency.labels.assert_called_once_with(endpoint_name='example', status='failure')
         mock_latency.labels.return_value.observe.assert_called_once()
 
     @patch('check_http_endpoints.requests.request')
@@ -67,7 +67,7 @@ def test_check_endpoint_request_exception(self, mock_success, mock_failure, mock
         mock_failure.labels.assert_called_once_with(endpoint_name='example')
         mock_failure.labels.return_value.inc.assert_called_once()
         mock_success.labels.assert_not_called()
-        mock_latency.labels.assert_called_once_with(endpoint_name='example')
+        mock_latency.labels.assert_called_once_with(endpoint_name='example', status='failure')
         mock_latency.labels.return_value.observe.assert_called_once()
 
     @patch('check_http_endpoints.time.time')
@@ -79,6 +79,7 @@ def test_latency_metric(self, mock_success, mock_failure, mock_latency, mock_req
         """Test that latency is recorded for endpoint checks."""
         mock_response = MagicMock()
         mock_response.ok = True
+        mock_response.elapsed.total_seconds.return_value = 0.5
         mock_request.return_value = mock_response
         mock_time.side_effect = [100, 100.5]
 
@@ -87,7 +88,7 @@ def test_latency_metric(self, mock_success, mock_failure, mock_latency, mock_req
         endpoint = Endpoint(name="example", url="http://example.com")
 
         checker.check_endpoint(endpoint)
-        mock_latency.labels.assert_called_once_with(endpoint_name='example')
+        mock_latency.labels.assert_called_once_with(endpoint_name='example', status='success')
         mock_latency.labels.return_value.observe.assert_called_once_with(0.5)
 
     def test_init_invalid_parameters(self):