feat(gateway,deployer): add more tracing events (#500)

* feat(deployer): add more tracing events

* feat(gateway): add more tracing events

Author: akrantz01

deployer/src/handlers/mod.rs

@@ -19,7 +19,7 @@ use shuttle_common::project::ProjectName;
 use shuttle_common::LogItem;
 use tower_http::auth::RequireAuthorizationLayer;
 use tower_http::trace::TraceLayer;
-use tracing::{debug, debug_span, error, field, trace, Span};
+use tracing::{debug, debug_span, error, field, instrument, trace, Span};
 use tracing_opentelemetry::OpenTelemetrySpanExt;
 use uuid::Uuid;
 
@@ -121,6 +121,7 @@ pub fn make_router(
         .layer(Extension(project_name))
 }
 
+#[instrument(skip_all)]
 async fn list_services(
     Extension(persistence): Extension<Persistence>,
 ) -> Result<Json<Vec<shuttle_common::models::service::Response>>> {
@@ -134,9 +135,10 @@ async fn list_services(
     Ok(Json(services))
 }
 
+#[instrument(skip(persistence))]
 async fn get_service(
     Extension(persistence): Extension<Persistence>,
-    Path((_project_name, service_name)): Path<(String, String)>,
+    Path((project_name, service_name)): Path<(String, String)>,
 ) -> Result<Json<shuttle_common::models::service::Detailed>> {
     if let Some(service) = persistence.get_service_by_name(&service_name).await? {
         let deployments = persistence
@@ -171,10 +173,11 @@ async fn get_service(
     }
 }
 
+#[instrument(skip_all, fields(%project_name, %service_name))]
 async fn get_service_summary(
     Extension(persistence): Extension<Persistence>,
     Extension(proxy_fqdn): Extension<FQDN>,
-    Path((_, service_name)): Path<(String, String)>,
+    Path((project_name, service_name)): Path<(String, String)>,
 ) -> Result<Json<shuttle_common::models::service::Summary>> {
     if let Some(service) = persistence.get_service_by_name(&service_name).await? {
         let deployment = persistence
@@ -201,10 +204,11 @@ async fn get_service_summary(
     }
 }
 
+#[instrument(skip_all, fields(%project_name, %service_name))]
 async fn post_service(
     Extension(persistence): Extension<Persistence>,
     Extension(deployment_manager): Extension<DeploymentManager>,
-    Path((_project_name, service_name)): Path<(String, String)>,
+    Path((project_name, service_name)): Path<(String, String)>,
     Query(params): Query<HashMap<String, String>>,
     mut stream: BodyStream,
 ) -> Result<Json<shuttle_common::models::deployment::Response>> {
@@ -243,10 +247,11 @@ async fn post_service(
     Ok(Json(deployment.into()))
 }
 
+#[instrument(skip_all, fields(%project_name, %service_name))]
 async fn delete_service(
     Extension(persistence): Extension<Persistence>,
     Extension(deployment_manager): Extension<DeploymentManager>,
-    Path((_project_name, service_name)): Path<(String, String)>,
+    Path((project_name, service_name)): Path<(String, String)>,
 ) -> Result<Json<shuttle_common::models::service::Detailed>> {
     if let Some(service) = persistence.get_service_by_name(&service_name).await? {
         let old_deployments = persistence
@@ -285,9 +290,10 @@ async fn delete_service(
     }
 }
 
+#[instrument(skip_all, fields(%project_name, %deployment_id))]
 async fn get_deployment(
     Extension(persistence): Extension<Persistence>,
-    Path((_project_name, deployment_id)): Path<(String, Uuid)>,
+    Path((project_name, deployment_id)): Path<(String, Uuid)>,
 ) -> Result<Json<shuttle_common::models::deployment::Response>> {
     if let Some(deployment) = persistence.get_deployment(&deployment_id).await? {
         Ok(Json(deployment.into()))
@@ -296,10 +302,11 @@ async fn get_deployment(
     }
 }
 
+#[instrument(skip_all, fields(%project_name, %deployment_id))]
 async fn delete_deployment(
     Extension(deployment_manager): Extension<DeploymentManager>,
     Extension(persistence): Extension<Persistence>,
-    Path((_project_name, deployment_id)): Path<(String, Uuid)>,
+    Path((project_name, deployment_id)): Path<(String, Uuid)>,
 ) -> Result<Json<shuttle_common::models::deployment::Response>> {
     if let Some(deployment) = persistence.get_deployment(&deployment_id).await? {
         deployment_manager.kill(deployment.id).await;
@@ -310,9 +317,10 @@ async fn delete_deployment(
     }
 }
 
+#[instrument(skip_all, fields(%project_name, %deployment_id))]
 async fn get_logs(
     Extension(persistence): Extension<Persistence>,
-    Path((_project_name, deployment_id)): Path<(String, Uuid)>,
+    Path((project_name, deployment_id)): Path<(String, Uuid)>,
 ) -> Result<Json<Vec<LogItem>>> {
     if let Some(deployment) = persistence.get_deployment(&deployment_id).await? {
         Ok(Json(
@@ -389,9 +397,10 @@ async fn logs_websocket_handler(mut s: WebSocket, persistence: Persistence, id:
     let _ = s.close().await;
 }
 
+#[instrument(skip_all, fields(%project_name, %service_name))]
 async fn get_secrets(
     Extension(persistence): Extension<Persistence>,
-    Path((_project_name, service_name)): Path<(String, String)>,
+    Path((project_name, service_name)): Path<(String, String)>,
 ) -> Result<Json<Vec<secret::Response>>> {
     if let Some(service) = persistence.get_service_by_name(&service_name).await? {
         let keys = persistence

deployer/src/lib.rs

@@ -37,7 +37,9 @@ pub async fn start(
         args.artifacts_path,
     );
 
-    for existing_deployment in persistence.get_all_runnable_deployments().await.unwrap() {
+    let runnable_deployments = persistence.get_all_runnable_deployments().await.unwrap();
+    info!(count = %runnable_deployments.len(), "enqueuing runnable deployments");
+    for existing_deployment in runnable_deployments {
         let built = Built {
             id: existing_deployment.id,
             service_name: existing_deployment.service_name,
@@ -56,7 +58,7 @@ pub async fn start(
     );
     let make_service = router.into_make_service();
 
-    info!("Binding to and listening at address: {}", args.api_address);
+    info!(address=%args.api_address, "Binding to and listening at address");
 
     axum::Server::bind(&args.api_address)
         .serve(make_service)

gateway/src/api/latest.rs

@@ -20,7 +20,7 @@ use shuttle_common::models::error::ErrorKind;
 use shuttle_common::models::{project, user};
 use tokio::sync::mpsc::Sender;
 use tower_http::trace::TraceLayer;
-use tracing::{debug, debug_span, field, Span};
+use tracing::{debug, debug_span, field, instrument, Span};
 
 use crate::acme::{AcmeClient, CustomDomain};
 use crate::auth::{Admin, ScopedUser, User};
@@ -65,6 +65,7 @@ impl StatusResponse {
     }
 }
 
+#[instrument(skip_all, fields(%account_name))]
 async fn get_user(
     State(RouterState { service, .. }): State<RouterState>,
     Path(account_name): Path<AccountName>,
@@ -75,6 +76,7 @@ async fn get_user(
     Ok(AxumJson(user.into()))
 }
 
+#[instrument(skip_all, fields(%account_name))]
 async fn post_user(
     State(RouterState { service, .. }): State<RouterState>,
     Path(account_name): Path<AccountName>,
@@ -85,6 +87,7 @@ async fn post_user(
     Ok(AxumJson(user.into()))
 }
 
+#[instrument(skip(service))]
 async fn get_project(
     State(RouterState { service, .. }): State<RouterState>,
     ScopedUser { scope, .. }: ScopedUser,
@@ -98,6 +101,7 @@ async fn get_project(
     Ok(AxumJson(response))
 }
 
+#[instrument(skip_all, fields(%project))]
 async fn post_project(
     State(RouterState { service, sender }): State<RouterState>,
     User { name, .. }: User,
@@ -121,6 +125,7 @@ async fn post_project(
     Ok(AxumJson(response))
 }
 
+#[instrument(skip_all, fields(%project))]
 async fn delete_project(
     State(RouterState { service, sender }): State<RouterState>,
     ScopedUser { scope: project, .. }: ScopedUser,
@@ -149,6 +154,7 @@ async fn delete_project(
     Ok(AxumJson(response))
 }
 
+#[instrument(skip_all, fields(scope = %scoped_user.scope))]
 async fn route_project(
     State(RouterState { service, .. }): State<RouterState>,
     scoped_user: ScopedUser,
@@ -176,6 +182,7 @@ async fn get_status(State(RouterState { sender, .. }): State<RouterState>) -> Re
         .unwrap()
 }
 
+#[instrument(skip_all)]
 async fn revive_projects(
     _: Admin,
     State(RouterState { service, sender }): State<RouterState>,
@@ -185,6 +192,7 @@ async fn revive_projects(
         .map_err(|_| Error::from_kind(ErrorKind::Internal))
 }
 
+#[instrument(skip_all, fields(%email, ?acme_server))]
 async fn create_acme_account(
     _: Admin,
     Extension(acme_client): Extension<AcmeClient>,
@@ -196,6 +204,7 @@ async fn create_acme_account(
     Ok(AxumJson(res))
 }
 
+#[instrument(skip_all, fields(%project_name, %fqdn))]
 async fn request_acme_certificate(
     _: Admin,
     State(RouterState { service, sender }): State<RouterState>,

gateway/src/main.rs

@@ -19,7 +19,7 @@ use std::io::{self, Cursor};
 use std::path::{Path, PathBuf};
 use std::sync::Arc;
 use std::time::Duration;
-use tracing::{debug, error, info, info_span, trace, warn};
+use tracing::{debug, error, info, info_span, trace, warn, Instrument};
 use tracing_subscriber::{fmt, prelude::*, EnvFilter};
 
 #[tokio::main(flavor = "multi_thread")]
@@ -122,20 +122,26 @@ async fn start(db: SqlitePool, fs: PathBuf, args: StartArgs) -> io::Result<()> {
                         "running health checks",
                         healthcheck.num_projects = projects.len()
                     );
-                    let _ = span.enter();
-                    for (project_name, _) in projects {
-                        if let Ok(handle) = gateway
-                            .new_task()
-                            .project(project_name)
-                            .and_then(task::check_health())
-                            .send(&sender)
-                            .await
-                        {
-                            // we wait for the check to be done before
-                            // queuing up the next one
-                            handle.await
+
+                    let gateway = gateway.clone();
+                    let sender = sender.clone();
+                    async move {
+                        for (project_name, _) in projects {
+                            if let Ok(handle) = gateway
+                                .new_task()
+                                .project(project_name)
+                                .and_then(task::check_health())
+                                .send(&sender)
+                                .await
+                            {
+                                // we wait for the check to be done before
+                                // queuing up the next one
+                                handle.await
+                            }
                         }
                     }
+                    .instrument(span)
+                    .await;
                 }
             }
         }

gateway/src/project.rs

@@ -19,7 +19,7 @@ use once_cell::sync::Lazy;
 use rand::distributions::{Alphanumeric, DistString};
 use serde::{Deserialize, Serialize};
 use tokio::time::{self, timeout};
-use tracing::{debug, error};
+use tracing::{debug, error, instrument};
 
 use crate::{
     ContainerSettings, DockerContext, EndState, Error, ErrorKind, IntoTryState, ProjectName,
@@ -276,6 +276,7 @@ where
     type Next = Self;
     type Error = Infallible;
 
+    #[instrument(skip_all, fields(state = %self.state()))]
     async fn next(self, ctx: &Ctx) -> Result<Self::Next, Self::Error> {
         let previous = self.clone();
         let previous_state = previous.state();
@@ -557,6 +558,7 @@ where
     type Next = ProjectStarting;
     type Error = ProjectError;
 
+    #[instrument(skip_all)]
     async fn next(self, ctx: &Ctx) -> Result<Self::Next, Self::Error> {
         let container_name = self.container_name(ctx);
         let container = ctx
@@ -593,6 +595,7 @@ where
     type Next = ProjectStarted;
     type Error = ProjectError;
 
+    #[instrument(skip_all)]
     async fn next(self, ctx: &Ctx) -> Result<Self::Next, Self::Error> {
         let container_id = self.container.id.as_ref().unwrap();
         ctx.docker()
@@ -642,6 +645,7 @@ where
     type Next = ProjectReadying;
     type Error = ProjectError;
 
+    #[instrument(skip_all)]
     async fn next(self, ctx: &Ctx) -> Result<Self::Next, Self::Error> {
         time::sleep(Duration::from_secs(1)).await;
 
@@ -688,6 +692,7 @@ where
     type Next = Self;
     type Error = ProjectError;
 
+    #[instrument(skip_all)]
     async fn next(mut self, _ctx: &Ctx) -> Result<Self::Next, Self::Error> {
         Ok(self)
     }
@@ -781,6 +786,7 @@ where
 
     type Error = ProjectError;
 
+    #[instrument(skip_all)]
     async fn next(self, ctx: &Ctx) -> Result<Self::Next, Self::Error> {
         let Self { container } = self;
         ctx.docker()
@@ -808,6 +814,7 @@ where
     type Next = ProjectStarting;
     type Error = ProjectError;
 
+    #[instrument(skip_all)]
     async fn next(self, ctx: &Ctx) -> Result<Self::Next, Self::Error> {
         let container = self.container;
 
@@ -860,6 +867,7 @@ where
     type Next = ProjectDestroyed;
     type Error = ProjectError;
 
+    #[instrument(skip_all)]
     async fn next(self, ctx: &Ctx) -> Result<Self::Next, Self::Error> {
         let container_id = self.container.id.as_ref().unwrap();
         ctx.docker()
@@ -895,6 +903,7 @@ where
     type Next = ProjectDestroyed;
     type Error = ProjectError;
 
+    #[instrument(skip_all)]
     async fn next(self, _ctx: &Ctx) -> Result<Self::Next, Self::Error> {
         Ok(self)
     }
@@ -980,6 +989,7 @@ where
     type Next = Self;
     type Error = Infallible;
 
+    #[instrument(skip_all)]
     async fn next(self, _ctx: &Ctx) -> Result<Self::Next, Self::Error> {
         Ok(self)
     }