[Serve] Add http request latency (ray-project#32839)

Add http request latency metrics.

Signed-off-by: Jack He <[email protected]>

doc/source/serve/production-guide/monitoring.md

@@ -279,6 +279,9 @@ The following metrics are exposed by Ray Serve:
        * error_code
        * method
      - The number of non-200 HTTP responses returned by each deployment.
+   * - ``serve_http_request_latency_ms`` [*]
+     - * endpoint
+     - The end-to-end latency of HTTP requests (measured from the Serve HTTP proxy).
 ```
 [*] - only available when using HTTP calls  
 [**] - only available when using Python `ServeHandle` calls

python/ray/serve/_private/http_proxy.py

@@ -26,7 +26,11 @@
     set_socket_reuse_port,
 )
 from ray.serve._private.common import EndpointInfo, EndpointTag
-from ray.serve._private.constants import SERVE_LOGGER_NAME, SERVE_NAMESPACE
+from ray.serve._private.constants import (
+    SERVE_LOGGER_NAME,
+    SERVE_NAMESPACE,
+    DEFAULT_LATENCY_BUCKET_MS,
+)
 from ray.serve._private.long_poll import LongPollClient, LongPollNamespace
 from ray.serve._private.logging_utils import access_log_msg, configure_component_logger
 
@@ -291,6 +295,15 @@ def get_handle(name):
                 "method",
             ),
         )
+        self.processing_latency_tracker = metrics.Histogram(
+            "serve_http_request_latency_ms",
+            description=(
+                "The end-to-end latency of HTTP requests "
+                "(measured from the Serve HTTP proxy)."
+            ),
+            boundaries=DEFAULT_LATENCY_BUCKET_MS,
+            tag_keys=("route_prefix",),
+        )
 
     def _update_routes(self, endpoints: Dict[EndpointTag, EndpointInfo]) -> None:
         self.route_info: Dict[str, Tuple[EndpointTag, List[str]]] = dict()
@@ -370,6 +383,9 @@ async def __call__(self, scope, receive, send):
         start_time = time.time()
         status_code = await _send_request_to_handle(handle, scope, receive, send)
         latency_ms = (time.time() - start_time) * 1000.0
+        self.processing_latency_tracker.observe(
+            latency_ms, tags={"route_prefix": route_prefix}
+        )
         logger.info(
             access_log_msg(
                 method=scope["method"],

python/ray/serve/tests/test_metrics.py

@@ -56,9 +56,9 @@ def verify_metrics(do_assert=False):
             "serve_deployment_request_counter",
             "serve_deployment_replica_starts",
             # histogram
-            "deployment_processing_latency_ms_bucket",
-            "deployment_processing_latency_ms_count",
-            "deployment_processing_latency_ms_sum",
+            "serve_deployment_processing_latency_ms_bucket",
+            "serve_deployment_processing_latency_ms_count",
+            "serve_deployment_processing_latency_ms_sum",
             "serve_deployment_processing_latency_ms",
             # gauge
             "serve_replica_processing_queries",
@@ -120,6 +120,7 @@ def verify_metrics(expected_metrics, do_assert=False):
     # https://docs.ray.io/en/latest/serve/monitoring.html#metrics
     # Any updates here should be reflected there too.
     expected_metrics.append("serve_num_deployment_http_error_requests")
+    expected_metrics.append("serve_http_request_latency_ms")
 
     @serve.deployment(name="A")
     class A: