proxy: remove unused metrics (#826)

This PR removes the unused `request_duration_ms` and `response_duration_ms` histogram metrics from the proxy. It also removes them from the `simulate-proxy` script's output, and from `docs/proxy-metrics.md`

Closes #821

proxy/src/telemetry/metrics/mod.rs

@@ -61,10 +61,8 @@ pub use self::labels::DstLabels;
 #[derive(Debug, Clone)]
 struct Metrics {
     request_total: Metric<Counter, Arc<RequestLabels>>,
-    request_duration: Metric<Histogram, Arc<RequestLabels>>,
 
     response_total: Metric<Counter, Arc<ResponseLabels>>,
-    response_duration: Metric<Histogram, Arc<ResponseLabels>>,
     response_latency: Metric<Histogram, Arc<ResponseLabels>>,
 
     tcp_accept_open_total: Metric<Counter, Arc<TransportLabels>>,
@@ -152,25 +150,11 @@ impl Metrics {
             "A counter of the number of requests the proxy has received.",
         );
 
-        let request_duration = Metric::<Histogram, Arc<RequestLabels>>::new(
-            "request_duration_ms",
-            "A histogram of the duration of a request. This is measured from \
-             when the request headers are received to when the request \
-             stream has completed.",
-        );
-
         let response_total = Metric::<Counter, Arc<ResponseLabels>>::new(
             "response_total",
             "A counter of the number of responses the proxy has received.",
         );
 
-        let response_duration = Metric::<Histogram, Arc<ResponseLabels>>::new(
-            "response_duration_ms",
-            "A histogram of the duration of a response. This is measured from \
-             when the response headers are received to when the response \
-             stream has completed.",
-        );
-
         let response_latency = Metric::<Histogram, Arc<ResponseLabels>>::new(
             "response_latency_ms",
             "A histogram of the total latency of a response. This is measured \
@@ -219,9 +203,7 @@ impl Metrics {
 
         Metrics {
             request_total,
-            request_duration,
             response_total,
-            response_duration,
             response_latency,
             tcp_accept_open_total,
             tcp_accept_close_total,
@@ -242,22 +224,6 @@ impl Metrics {
             .or_insert_with(Counter::default)
     }
 
-    fn request_duration(&mut self,
-                        labels: &Arc<RequestLabels>)
-                        -> &mut Histogram {
-        self.request_duration.values
-            .entry(labels.clone())
-            .or_insert_with(Histogram::default)
-    }
-
-    fn response_duration(&mut self,
-                         labels: &Arc<ResponseLabels>)
-                         -> &mut Histogram {
-        self.response_duration.values
-            .entry(labels.clone())
-            .or_insert_with(Histogram::default)
-    }
-
     fn response_latency(&mut self,
                         labels: &Arc<ResponseLabels>)
                         -> &mut Histogram {
@@ -334,9 +300,7 @@ impl Metrics {
 impl fmt::Display for Metrics {
     fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
         writeln!(f, "{}", self.request_total)?;
-        writeln!(f, "{}", self.request_duration)?;
         writeln!(f, "{}", self.response_total)?;
-        writeln!(f, "{}", self.response_duration)?;
         writeln!(f, "{}", self.response_latency)?;
         writeln!(f, "{}", self.tcp_accept_open_total)?;
         writeln!(f, "{}", self.tcp_accept_close_total)?;
@@ -504,21 +468,17 @@ impl Aggregate {
                 //  when the stream *finishes*.
             },
 
-            Event::StreamRequestFail(ref req, ref fail) => {
+            Event::StreamRequestFail(ref req, _) => {
                 let labels = Arc::new(RequestLabels::new(req));
                 self.update(|metrics| {
-                    *metrics.request_duration(&labels) +=
-                        fail.since_request_open;
                     *metrics.request_total(&labels).incr();
                 })
             },
 
-            Event::StreamRequestEnd(ref req, ref end) => {
+            Event::StreamRequestEnd(ref req, _) => {
                 let labels = Arc::new(RequestLabels::new(req));
                 self.update(|metrics| {
                     *metrics.request_total(&labels).incr();
-                    *metrics.request_duration(&labels) +=
-                        end.since_request_open;
                 })
             },
 
@@ -529,7 +489,6 @@ impl Aggregate {
                 ));
                 self.update(|metrics| {
                     *metrics.response_total(&labels).incr();
-                    *metrics.response_duration(&labels) +=  end.since_response_open;
                     *metrics.response_latency(&labels) += end.since_request_open;
                 });
             },
@@ -539,7 +498,6 @@ impl Aggregate {
                 let labels = Arc::new(ResponseLabels::fail(res));
                 self.update(|metrics| {
                     *metrics.response_total(&labels).incr();
-                    *metrics.response_duration(&labels) += fail.since_response_open;
                     *metrics.response_latency(&labels) += fail.since_request_open;
                 });
             },

proxy/tests/telemetry.rs

@@ -403,48 +403,6 @@ fn metrics_endpoint_outbound_response_latency() {
         "response_latency_ms_count{authority=\"tele.test.svc.cluster.local\",direction=\"outbound\",classification=\"success\",status_code=\"200\"} 4");
 }
 
-// https://github.com/runconduit/conduit/issues/613
-#[test]
-#[cfg_attr(not(feature = "flaky_tests"), ignore)]
-fn metrics_endpoint_inbound_request_duration() {
-    let _ = env_logger::try_init();
-    let Fixture { client, metrics, proxy: _proxy } = Fixture::inbound();
-
-    // request with body should increment request_duration
-    info!("client.get(/)");
-    assert_eq!(client.get("/"), "hello");
-
-    assert_contains!(metrics.get("/metrics"),
-        "request_duration_ms_count{authority=\"tele.test.svc.cluster.local\",direction=\"inbound\"} 1");
-
-    // request without body should also increment request_duration
-    info!("client.get(/)");
-    assert_eq!(client.get("/"), "hello");
-
-    assert_contains!(metrics.get("/metrics"),
-        "request_duration_ms_count{authority=\"tele.test.svc.cluster.local\",direction=\"inbound\"} 2");
-}
-
-// https://github.com/runconduit/conduit/issues/613
-#[test]
-#[cfg_attr(not(feature = "flaky_tests"), ignore)]
-fn metrics_endpoint_outbound_request_duration() {
-    let _ = env_logger::try_init();
-    let Fixture { client, metrics, proxy: _proxy } = Fixture::outbound();
-
-    info!("client.get(/)");
-    assert_eq!(client.get("/"), "hello");
-
-    assert_contains!(metrics.get("/metrics"),
-        "request_duration_ms_count{authority=\"tele.test.svc.cluster.local\",direction=\"outbound\"} 1");
-
-    info!("client.get(/)");
-    assert_eq!(client.get("/"), "hello");
-
-    assert_contains!(metrics.get("/metrics"),
-        "request_duration_ms_count{authority=\"tele.test.svc.cluster.local\",direction=\"outbound\"} 2");
-}
-
 // Tests for destination labels provided by control plane service discovery.
 mod outbound_dst_labels {
     use super::support::*;
@@ -544,9 +502,7 @@ mod outbound_dst_labels {
         info!("client.get(/)");
         assert_eq!(client.get("/"), "hello");
         assert_contains!(metrics.get("/metrics"),
-            "request_duration_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_addr_label=\"foo\",dst_set_label=\"bar\"} 1");
+            "response_latency_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_addr_label=\"foo\",dst_set_label=\"bar\",classification=\"success\",status_code=\"200\"} 1");
-        assert_contains!(metrics.get("/metrics"),
-            "response_duration_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_addr_label=\"foo\",dst_set_label=\"bar\",classification=\"success\",status_code=\"200\"} 1");
         assert_contains!(metrics.get("/metrics"),
             "request_total{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_addr_label=\"foo\",dst_set_label=\"bar\"} 1");
         assert_contains!(metrics.get("/metrics"),
@@ -578,9 +534,7 @@ mod outbound_dst_labels {
         assert_eq!(client.get("/"), "hello");
         // the first request should be labeled with `dst_addr_label="foo"`
         assert_contains!(metrics.get("/metrics"),
-            "request_duration_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_addr_label=\"foo\",dst_set_label=\"unchanged\"} 1");
+            "response_latency_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_addr_label=\"foo\",dst_set_label=\"unchanged\",classification=\"success\",status_code=\"200\"} 1");
-        assert_contains!(metrics.get("/metrics"),
-            "response_duration_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_addr_label=\"foo\",dst_set_label=\"unchanged\",classification=\"success\",status_code=\"200\"} 1");
         assert_contains!(metrics.get("/metrics"),
             "request_total{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_addr_label=\"foo\",dst_set_label=\"unchanged\"} 1");
         assert_contains!(metrics.get("/metrics"),
@@ -598,18 +552,14 @@ mod outbound_dst_labels {
         assert_eq!(client.get("/"), "hello");
         // the second request should increment stats labeled with `dst_addr_label="bar"`
         assert_contains!(metrics.get("/metrics"),
-            "request_duration_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_addr_label=\"bar\",dst_set_label=\"unchanged\"} 1");
+            "response_latency_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_addr_label=\"bar\",dst_set_label=\"unchanged\",classification=\"success\",status_code=\"200\"} 1");
-        assert_contains!(metrics.get("/metrics"),
-            "response_duration_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_addr_label=\"bar\",dst_set_label=\"unchanged\",classification=\"success\",status_code=\"200\"} 1");
         assert_contains!(metrics.get("/metrics"),
             "request_total{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_addr_label=\"bar\",dst_set_label=\"unchanged\"} 1");
         assert_contains!(metrics.get("/metrics"),
             "response_total{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_addr_label=\"bar\",dst_set_label=\"unchanged\",classification=\"success\",status_code=\"200\"} 1");
         // stats recorded from the first request should still be present.
         assert_contains!(metrics.get("/metrics"),
-            "request_duration_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_addr_label=\"foo\",dst_set_label=\"unchanged\"} 1");
+            "response_latency_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_addr_label=\"foo\",dst_set_label=\"unchanged\",classification=\"success\",status_code=\"200\"} 1");
-        assert_contains!(metrics.get("/metrics"),
-            "response_duration_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_addr_label=\"foo\",dst_set_label=\"unchanged\",classification=\"success\",status_code=\"200\"} 1");
         assert_contains!(metrics.get("/metrics"),
             "request_total{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_addr_label=\"foo\",dst_set_label=\"unchanged\"} 1");
         assert_contains!(metrics.get("/metrics"),
@@ -639,9 +589,7 @@ mod outbound_dst_labels {
         assert_eq!(client.get("/"), "hello");
         // the first request should be labeled with `dst_addr_label="foo"`
         assert_contains!(metrics.get("/metrics"),
-            "request_duration_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_set_label=\"foo\"} 1");
+            "response_latency_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_set_label=\"foo\",classification=\"success\",status_code=\"200\"} 1");
-        assert_contains!(metrics.get("/metrics"),
-            "response_duration_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_set_label=\"foo\",classification=\"success\",status_code=\"200\"} 1");
         assert_contains!(metrics.get("/metrics"),
             "request_total{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_set_label=\"foo\"} 1");
         assert_contains!(metrics.get("/metrics"),
@@ -658,18 +606,14 @@ mod outbound_dst_labels {
         assert_eq!(client.get("/"), "hello");
         // the second request should increment stats labeled with `dst_addr_label="bar"`
         assert_contains!(metrics.get("/metrics"),
-            "request_duration_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_set_label=\"bar\"} 1");
+            "response_latency_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_set_label=\"bar\",classification=\"success\",status_code=\"200\"} 1");
-        assert_contains!(metrics.get("/metrics"),
-            "response_duration_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_set_label=\"bar\",classification=\"success\",status_code=\"200\"} 1");
         assert_contains!(metrics.get("/metrics"),
             "request_total{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_set_label=\"bar\"} 1");
         assert_contains!(metrics.get("/metrics"),
             "response_total{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_set_label=\"bar\",classification=\"success\",status_code=\"200\"} 1");
         // stats recorded from the first request should still be present.
         assert_contains!(metrics.get("/metrics"),
-            "request_duration_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_set_label=\"foo\"} 1");
+            "response_latency_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_set_label=\"foo\",classification=\"success\",status_code=\"200\"} 1");
-        assert_contains!(metrics.get("/metrics"),
-            "response_duration_ms_count{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_set_label=\"foo\",classification=\"success\",status_code=\"200\"} 1");
         assert_contains!(metrics.get("/metrics"),
             "request_total{authority=\"labeled.test.svc.cluster.local\",direction=\"outbound\",dst_set_label=\"foo\"} 1");
         assert_contains!(metrics.get("/metrics"),