diff --git a/src/authenticator.rs b/src/authenticator.rs index 9d0feda..6b71424 100644 --- a/src/authenticator.rs +++ b/src/authenticator.rs @@ -10,6 +10,7 @@ use crate::types::{AccessToken, ApplicationSecret, TokenInfo}; use private::AuthFlow; use std::borrow::Cow; +use std::fmt; use std::io; use std::path::PathBuf; use std::sync::Mutex; @@ -22,6 +23,25 @@ pub struct Authenticator { auth_flow: AuthFlow, } +struct DisplayScopes<'a, T>(&'a [T]); +impl<'a, T> fmt::Display for DisplayScopes<'a, T> +where + T: AsRef, +{ + fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result { + f.write_str("[")?; + let mut iter = self.0.iter(); + if let Some(first) = iter.next() { + f.write_str(first.as_ref())?; + for scope in iter { + f.write_str(", ")?; + f.write_str(scope.as_ref())?; + } + } + f.write_str("]") + } +} + impl Authenticator where C: hyper::client::connect::Connect + 'static, @@ -31,10 +51,15 @@ where where T: AsRef, { + log::debug!( + "access token requested for scopes: {}", + DisplayScopes(scopes) + ); let hashed_scopes = storage::ScopeSet::from(scopes); match (self.storage.get(hashed_scopes), self.auth_flow.app_secret()) { (Some(t), _) if !t.is_expired() => { // unexpired token found + log::debug!("found valid token in cache: {:?}", t); Ok(t.into()) } ( diff --git a/src/device.rs b/src/device.rs index b21098b..092cb80 100644 --- a/src/device.rs +++ b/src/device.rs @@ -55,6 +55,7 @@ impl DeviceFlow { scopes, ) .await?; + log::debug!("Presenting code to user"); self.flow_delegate .present_user_code(&device_auth_resp) .await; @@ -78,6 +79,7 @@ impl DeviceFlow { C: hyper::client::connect::Connect + 'static, { let mut interval = device_auth_resp.interval; + log::debug!("Polling every {:?} for device token", interval); loop { tokio::timer::delay_for(interval).await; interval = match Self::poll_token( @@ -92,10 +94,16 @@ impl DeviceFlow { Err(Error::AuthError(AuthError { error, .. })) if error.as_str() == "authorization_pending" => { + log::debug!("still waiting on authorization from the server"); interval } Err(Error::AuthError(AuthError { error, .. })) if error.as_str() == "slow_down" => { - interval + Duration::from_secs(5) + let interval = interval + Duration::from_secs(5); + log::debug!( + "server requested slow_down. Increasing polling interval to {:?}", + interval + ); + interval } Err(err) => return Err(err), } @@ -140,8 +148,10 @@ impl DeviceFlow { .header(header::CONTENT_TYPE, "application/x-www-form-urlencoded") .body(hyper::Body::from(req)) .unwrap(); - let resp = client.request(req).await?; - let body = resp.into_body().try_concat().await?; + log::debug!("requesting code from server: {:?}", req); + let (head, body) = client.request(req).await?.into_parts(); + let body = body.try_concat().await?; + log::debug!("received response; head: {:?}, body: {:?}", head, body); DeviceAuthResponse::from_json(&body) } @@ -186,8 +196,10 @@ impl DeviceFlow { .header(header::CONTENT_TYPE, "application/x-www-form-urlencoded") .body(hyper::Body::from(req)) .unwrap(); // TODO: Error checking - let res = client.request(request).await?; - let body = res.into_body().try_concat().await?; + log::debug!("polling for token: {:?}", request); + let (head, body) = client.request(request).await?.into_parts(); + let body = body.try_concat().await?; + log::debug!("received response; head: {:?} body: {:?}", head, body); TokenInfo::from_json(&body) } } diff --git a/src/installed.rs b/src/installed.rs index 4a6bebd..fd85154 100644 --- a/src/installed.rs +++ b/src/installed.rs @@ -126,12 +126,14 @@ impl InstalledFlow { scopes, self.flow_delegate.redirect_uri(), ); - let authcode = self + log::debug!("Presenting auth url to user: {}", url); + let auth_code = self .flow_delegate .present_user_url(&url, true /* need code */) .await .map_err(Error::UserError)?; - self.exchange_auth_code(&authcode, hyper_client, app_secret, None) + log::debug!("Received auth code: {}", auth_code); + self.exchange_auth_code(&auth_code, hyper_client, app_secret, None) .await } @@ -162,11 +164,11 @@ impl InstalledFlow { scopes, Some(redirect_uri.as_ref()), ); + log::debug!("Presenting auth url to user: {}", url); let _ = self .flow_delegate .present_user_url(&url, false /* need code */) .await; - let auth_code = server.wait_for_auth_code().await; self.exchange_auth_code(&auth_code, hyper_client, app_secret, Some(server_addr)) .await @@ -184,8 +186,10 @@ impl InstalledFlow { { let redirect_uri = self.flow_delegate.redirect_uri(); let request = Self::request_token(app_secret, authcode, redirect_uri, server_addr); - let resp = hyper_client.request(request).await?; - let body = resp.into_body().try_concat().await?; + log::debug!("Sending request: {:?}", request); + let (head, body) = hyper_client.request(request).await?.into_parts(); + let body = body.try_concat().await?; + log::debug!("Received response; head: {:?} body: {:?}", head, body); TokenInfo::from_json(&body) } @@ -265,6 +269,7 @@ impl InstalledFlowServer { }) .await; }); + log::debug!("HTTP server listening on {}", addr); Ok(InstalledFlowServer { addr, auth_code_rx, @@ -278,11 +283,14 @@ impl InstalledFlowServer { } async fn wait_for_auth_code(self) -> String { + log::debug!("Waiting for HTTP server to receive auth code"); // Wait for the auth code from the server. let auth_code = self .auth_code_rx .await .expect("server shutdown while waiting for auth_code"); + log::debug!("HTTP server received auth code: {}", auth_code); + log::debug!("Shutting down HTTP server"); // auth code received. shutdown the server let _ = self.trigger_shutdown_tx.send(()); self.shutdown_complete.await; diff --git a/src/refresh.rs b/src/refresh.rs index 0ce14bf..3e28f87 100644 --- a/src/refresh.rs +++ b/src/refresh.rs @@ -32,6 +32,10 @@ impl RefreshFlow { client_secret: &ApplicationSecret, refresh_token: &str, ) -> Result { + log::debug!( + "refreshing access token with refresh token: {}", + refresh_token + ); let req = form_urlencoded::Serializer::new(String::new()) .extend_pairs(&[ ("client_id", client_secret.client_id.as_str()), @@ -45,9 +49,10 @@ impl RefreshFlow { .header(header::CONTENT_TYPE, "application/x-www-form-urlencoded") .body(hyper::Body::from(req)) .unwrap(); - - let resp = client.request(request).await?; - let body = resp.into_body().try_concat().await?; + log::debug!("Sending request: {:?}", request); + let (head, body) = client.request(request).await?.into_parts(); + let body = body.try_concat().await?; + log::debug!("Received response; head: {:?}, body: {:?}", head, body); let mut token = TokenInfo::from_json(&body)?; // If the refresh result contains a refresh_token use it, otherwise // continue using our previous refresh_token. diff --git a/src/service_account.rs b/src/service_account.rs index 55c545f..2427f7c 100644 --- a/src/service_account.rs +++ b/src/service_account.rs @@ -200,8 +200,10 @@ impl ServiceAccountFlow { .header(header::CONTENT_TYPE, "application/x-www-form-urlencoded") .body(hyper::Body::from(rqbody)) .unwrap(); - let response = hyper_client.request(request).await?; - let body = response.into_body().try_concat().await?; + log::debug!("requesting token from service account: {:?}", request); + let (head, body) = hyper_client.request(request).await?.into_parts(); + let body = body.try_concat().await?; + log::debug!("received response; head: {:?}, body: {:?}", head, body); TokenInfo::from_json(&body) } } diff --git a/src/storage.rs b/src/storage.rs index 89ed9c2..2a6f274 100644 --- a/src/storage.rs +++ b/src/storage.rs @@ -227,7 +227,7 @@ impl<'de> Deserialize<'de> for JSONTokens { } // Instantiate our Visitor and ask the Deserializer to drive - // it over the input data, resulting in an instance of MyMap. + // it over the input data. deserializer.deserialize_seq(V) } }