Auto merge of #3156 - jtgeibel:record-start-instant-after-headers, r=Turbo87

Use new conduit API when computing elapsed time

The request start time is now captured by a `conduit` based server. This
ensures that the logged elapsed time is accurate, even if the request
queues waiting for a background thread to run on.

Relevent upstream changes:

* conduit-rust/conduit@v0.9.0-alpha.3...v0.9.0-alpha.5
* conduit-rust/rust-civet@v0.12.0-alpha.4...v0.12.0-alpha.5
* conduit-rust/conduit-hyper@v0.3.0-alpha.5...v0.3.0-alpha.5.1

Unrelated upstream changes (minor API cleanup):

* conduit-rust/conduit-test@v0.9.0-alpha.3...v0.9.0-alpha.4
* conduit-rust/conduit-middleware@v0.9.0-alpha.3...v0.9.0-alpha.4

r? `@Turbo87`
cc `@pietroalbini`

Author: bors

Cargo.lock

@@ -34,16 +34,16 @@ anyhow = "1.0"
 base64 = "0.13"
 cargo-registry-s3 = { path = "src/s3", version = "0.2.0" }
 chrono = { version = "0.4.0", features = ["serde"] }
-civet = "0.12.0-alpha.4"
+civet = "0.12.0-alpha.5"
 clap = "=3.0.0-beta.2"
 comrak = { version = "0.9", default-features = false }
 
-conduit = "0.9.0-alpha.3"
+conduit = "0.9.0-alpha.5"
 conduit-conditional-get = "0.9.0-alpha.3"
 conduit-cookie = "0.9.0-alpha.4"
 conduit-git-http-backend = "0.9.0-alpha.2"
-conduit-hyper = "=0.3.0-alpha.5"
-conduit-middleware = "0.9.0-alpha.3"
+conduit-hyper = "=0.3.0-alpha.5.1"
+conduit-middleware = "0.9.0-alpha.4"
 conduit-router = "0.9.0-alpha.3"
 conduit-static = "0.9.0-alpha.3"
 
@@ -89,7 +89,7 @@ url = "2.1"
 
 [dev-dependencies]
 claim = "0.4.0"
-conduit-test = "0.9.0-alpha.3"
+conduit-test = "0.9.0-alpha.4"
 diesel_migrations = { version = "1.3.0", features = ["postgres"] }
 hyper-tls = "0.4"
 lazy_static = "1.0"

Cargo.toml

@@ -4,10 +4,11 @@
 use super::prelude::*;
 use crate::middleware::current_user::TrustedUserId;
 use crate::util::request_header;
+
 use conduit::{header, Host, RequestExt, Scheme, StatusCode};
 use sentry::Level;
+
 use std::fmt::{self, Display, Formatter};
-use std::time::Instant;
 
 const SLOW_REQUEST_THRESHOLD_MS: u64 = 1000;
 
@@ -16,22 +17,17 @@ const FILTERED_HEADERS: &[&str] = &["Authorization", "Cookie", "X-Real-Ip", "X-F
 #[derive(Default)]
 pub(super) struct LogRequests();
 
-struct RequestStart(Instant);
 struct OriginalPath(String);
 
 impl Middleware for LogRequests {
     fn before(&self, req: &mut dyn RequestExt) -> BeforeResult {
-        req.mut_extensions().insert(RequestStart(Instant::now()));
         let path = OriginalPath(req.path().to_string());
         req.mut_extensions().insert(path);
         Ok(())
     }
 
     fn after(&self, req: &mut dyn RequestExt, res: AfterResult) -> AfterResult {
-        // Unwrap shouldn't panic as no other code has access to the private struct to remove it
-        let request_start = req.extensions().find::<RequestStart>().unwrap().0;
-
-        let response_time = request_start.elapsed();
+        let response_time = req.elapsed();
         let response_time =
             response_time.as_secs() * 1000 + u64::from(response_time.subsec_nanos()) / 1_000_000;