Add request/response traces (#397)

* Add request/response traces

* Fix clippy lint

rust-runtime/smithy-http-tower/src/dispatch.rs

@@ -4,19 +4,13 @@
  */
 
 use crate::SendOperationError;
-use pin_project::pin_project;
 use smithy_http::body::SdkBody;
 use smithy_http::operation;
 use std::future::Future;
 use std::pin::Pin;
 use std::task::{Context, Poll};
 use tower::{BoxError, Layer, Service};
-
-#[pin_project]
-pub struct DispatchFuture<F> {
-    #[pin]
-    f: F,
-}
+use tracing::trace;
 
 /// Connects Operation driven middleware to an HTTP implementation.
 ///
@@ -27,29 +21,17 @@ pub struct DispatchService<S> {
     inner: S,
 }
 
-impl<F, T, E> Future for DispatchFuture<F>
-where
-    F: Future<Output = Result<T, E>>,
-    E: Into<BoxError>,
-{
-    type Output = Result<T, SendOperationError>;
-
-    fn poll(self: Pin<&mut Self>, cx: &mut Context<'_>) -> Poll<Self::Output> {
-        let this = self.project();
-        this.f
-            .poll(cx)
-            .map_err(|e| SendOperationError::RequestDispatchError(e.into()))
-    }
-}
+type BoxedResultFuture<T, E> = Pin<Box<dyn Future<Output = Result<T, E>> + Send>>;
 
 impl<S> Service<operation::Request> for DispatchService<S>
 where
-    S: Service<http::Request<SdkBody>>,
+    S: Service<http::Request<SdkBody>> + Clone + Send + 'static,
     S::Error: Into<BoxError>,
+    S::Future: Send + 'static,
 {
     type Response = S::Response;
     type Error = SendOperationError;
-    type Future = DispatchFuture<S::Future>;
+    type Future = BoxedResultFuture<Self::Response, Self::Error>;
 
     fn poll_ready(&mut self, cx: &mut Context<'_>) -> Poll<Result<(), Self::Error>> {
         self.inner
@@ -59,9 +41,15 @@ where
 
     fn call(&mut self, req: operation::Request) -> Self::Future {
         let (req, _property_bag) = req.into_parts();
-        DispatchFuture {
-            f: self.inner.call(req),
-        }
+        let mut inner = self.inner.clone();
+        let future = async move {
+            trace!(request = ?req);
+            inner
+                .call(req)
+                .await
+                .map_err(|e| SendOperationError::RequestDispatchError(e.into()))
+        };
+        Box::pin(future)
     }
 }
 

rust-runtime/smithy-http/Cargo.toml

@@ -13,6 +13,7 @@ http = "0.2.3"
 thiserror = "1"
 pin-project = "1"
 percent-encoding = "2.1.0"
+tracing = "0.1.24"
 
 # We are using hyper for our streaming body implementation, but this is an internal detail.
 hyper = "0.14.5"

rust-runtime/smithy-http/src/middleware.rs

@@ -17,6 +17,7 @@ use bytes::{Buf, Bytes};
 use http::Response;
 use http_body::Body;
 use std::error::Error;
+use tracing::trace;
 
 type BoxError = Box<dyn Error + Send + Sync>;
 
@@ -78,8 +79,10 @@ where
     if let Some(parsed_response) = handler.parse_unloaded(&mut response) {
         return sdk_result(parsed_response, response);
     }
-    let (parts, body) = response.into_parts();
 
+    trace!(response = ?response);
+
+    let (parts, body) = response.into_parts();
     let body = match read_body(body).await {
         Ok(body) => body,
         Err(err) => {