From 48e7c38d352ada806a531d04d58197a1ee424d44 Mon Sep 17 00:00:00 2001 From: Eugene Yakubovich Date: Mon, 31 Oct 2022 14:41:50 -0700 Subject: [PATCH] odyn: clean up the logs Reduce verbosity and fix "Staring" strings to be printed only if the given proxy is enabled. --- enclaver/src/bin/odyn/egress.rs | 5 ++++- enclaver/src/bin/odyn/ingress.rs | 3 +++ enclaver/src/bin/odyn/kms_proxy.rs | 1 + enclaver/src/bin/odyn/main.rs | 7 ------- enclaver/src/proxy/egress_http.rs | 10 +++------- enclaver/src/proxy/ingress.rs | 2 -- enclaver/src/vsock.rs | 20 ++++++++++---------- 7 files changed, 21 insertions(+), 27 deletions(-) diff --git a/enclaver/src/bin/odyn/egress.rs b/enclaver/src/bin/odyn/egress.rs index bf501103..91c038c6 100644 --- a/enclaver/src/bin/odyn/egress.rs +++ b/enclaver/src/bin/odyn/egress.rs @@ -2,8 +2,9 @@ use std::sync::Arc; use tokio::task::JoinHandle; use anyhow::Result; -use enclaver::constants::HTTP_EGRESS_VSOCK_PORT; +use log::info; +use enclaver::constants::HTTP_EGRESS_VSOCK_PORT; use enclaver::proxy::egress_http::EnclaveHttpProxy; use enclaver::policy::EgressPolicy; use crate::config::Configuration; @@ -15,6 +16,8 @@ pub struct EgressService { impl EgressService { pub async fn start(config: &Configuration) -> Result { let task = if let Some(proxy_uri) = config.egress_proxy_uri() { + info!("Startng egress"); + let policy = Arc::new(EgressPolicy::new(config.manifest.egress.as_ref().unwrap())); set_proxy_env_var(&proxy_uri.to_string()); diff --git a/enclaver/src/bin/odyn/ingress.rs b/enclaver/src/bin/odyn/ingress.rs index ac8784cf..faded5d2 100644 --- a/enclaver/src/bin/odyn/ingress.rs +++ b/enclaver/src/bin/odyn/ingress.rs @@ -1,5 +1,6 @@ use tokio::task::JoinHandle; use anyhow::Result; +use log::info; use enclaver::proxy::ingress::EnclaveProxy; use crate::config::{Configuration, ListenerConfig}; @@ -15,10 +16,12 @@ impl IngressService { for (port, cfg) in &config.listener_configs { match cfg { ListenerConfig::TCP => { + info!("Startng TCP ingress on port {}", *port); let proxy = EnclaveProxy::bind(*port)?; tasks.push(tokio::spawn(proxy.serve())); }, ListenerConfig::TLS(tls_cfg) => { + info!("Startng TLS ingress on port {}", *port); let proxy = EnclaveProxy::bind_tls(*port, tls_cfg.clone())?; tasks.push(tokio::spawn(proxy.serve())); }, diff --git a/enclaver/src/bin/odyn/kms_proxy.rs b/enclaver/src/bin/odyn/kms_proxy.rs index dfe496b4..a53e33c5 100644 --- a/enclaver/src/bin/odyn/kms_proxy.rs +++ b/enclaver/src/bin/odyn/kms_proxy.rs @@ -22,6 +22,7 @@ impl KmsProxyService { pub async fn start(config: Arc, nsm: Arc) -> Result { let task = if let Some(port) = config.kms_proxy_port() { if let Some(proxy_uri) = config.egress_proxy_uri() { + info!("Starting KMS proxy"); let attester = Box::new(NsmAttestationProvider::new(nsm)); // If a keypair will be needed elsewhere, this should be moved out diff --git a/enclaver/src/bin/odyn/main.rs b/enclaver/src/bin/odyn/main.rs index 01c8704d..9a21e592 100644 --- a/enclaver/src/bin/odyn/main.rs +++ b/enclaver/src/bin/odyn/main.rs @@ -55,11 +55,8 @@ async fn run(args: &CliArgs) -> Result<()> { info!("Enclave initialized"); } - info!("Startng egress"); let egress = EgressService::start(&config).await?; - info!("Startng ingress"); let ingress = IngressService::start(&config)?; - info!("Starting KMS proxy"); let kms_proxy = KmsProxyService::start(config.clone(), nsm.clone()).await?; let creds = launcher::Credentials{ @@ -71,12 +68,8 @@ async fn run(args: &CliArgs) -> Result<()> { let exit_status = launcher::start_child(args.entrypoint.clone(), creds).await??; info!("Entrypoint {}", exit_status); - info!("Stopping kms proxy"); kms_proxy.stop().await; - - info!("Stopping ingress"); ingress.stop().await; - info!("Stopping egress"); egress.stop().await; app_status.exited(exit_status); diff --git a/enclaver/src/proxy/egress_http.rs b/enclaver/src/proxy/egress_http.rs index 2765bc71..828f4c5a 100644 --- a/enclaver/src/proxy/egress_http.rs +++ b/enclaver/src/proxy/egress_http.rs @@ -172,7 +172,6 @@ impl HostHttpProxy { debug!("Connected to {}:{}, starting to proxy bytes", host, conn_req.port); _ = tokio::io::copy_bidirectional(&mut vsock, &mut tcp).await; - debug!("Proxying is done"); }, Err(err) => { ConnectResponse::failed(&err) @@ -198,8 +197,6 @@ async fn proxy(egress_port: u32, req: Request, } async fn handle_connect(egress_port: u32, req: Request, egress_policy: &EgressPolicy) -> Response { - debug!("Handling CONNECT request"); - match req.uri().authority() { Some(authority) => { let port = match authority.port() { @@ -217,19 +214,18 @@ async fn handle_connect(egress_port: u32, req: Request, egress_policy: &Eg } + debug!("Handling CONNECT to {}:{port}", authority.host()); + // Connect to remote server before the upgrade so we can return an error if it fails let mut remote = match remote_connect(egress_port, authority.host(), port).await { Ok(remote) => remote, Err(err) => return err_resp(http::StatusCode::SERVICE_UNAVAILABLE, err.to_string()), }; - debug!("Connected to origin server"); tokio::task::spawn(async move { match hyper::upgrade::on(req).await { Ok(mut upgraded) => { - debug!("Connection upgraded"); _ = tokio::io::copy_bidirectional(&mut upgraded, &mut remote).await; - debug!("Proxying is done"); } Err(err) => { error!("Upgrade failed: {err}"); @@ -240,7 +236,7 @@ async fn handle_connect(egress_port: u32, req: Request, egress_policy: &Eg Response::new(Body::empty()) }, None => { - let err_msg = format!("CONNECT host is not socket addr: {:?}", req.uri()); + let err_msg = format!("CONNECT host is not a socket addr: {:?}", req.uri()); error!("{err_msg}"); bad_request(err_msg) } diff --git a/enclaver/src/proxy/ingress.rs b/enclaver/src/proxy/ingress.rs index 75d7b829..b544eb86 100644 --- a/enclaver/src/proxy/ingress.rs +++ b/enclaver/src/proxy/ingress.rs @@ -62,7 +62,6 @@ where Ok(mut tcp) => { debug!("Connected to {target}, proxying data"); _ = tokio::io::copy_bidirectional(&mut vsock, &mut tcp).await; - debug!("Proxying is done"); }, Err(err) => error!("Connection to upstream ({target}) failed: {err}"), } @@ -99,7 +98,6 @@ impl HostProxy { Ok(mut vsock) => { debug!("Connected to {target_port}:{target_cid}, proxying data"); _ = tokio::io::copy_bidirectional(&mut vsock, &mut tcp).await; - debug!("Proxying is done"); }, Err(err) => error!("Connection to upstream vsock ({target_cid}:{target_port}) failed: {err}"), } diff --git a/enclaver/src/vsock.rs b/enclaver/src/vsock.rs index ebbc48b7..13122395 100644 --- a/enclaver/src/vsock.rs +++ b/enclaver/src/vsock.rs @@ -1,5 +1,5 @@ use std::sync::Arc; -use log::{info, error}; +use log::{info, debug, error}; use anyhow::{Result}; use rustls::{ServerConfig, ClientConfig}; use rustls::client::ServerName; @@ -19,18 +19,18 @@ pub type TlsClientStream = tokio_rustls::client::TlsStream; pub fn serve(port: u32) -> Result + Unpin> { let listener = VsockListener::bind(VMADDR_CID_ANY, port)?; - info!("Listening on vsock port {}", port); + info!("Listening on vsock port {port}"); let stream = listener.incoming() .filter_map(move |result| { futures::future::ready( match result { Ok(vsock) => { - info!("Connection accepted"); + debug!("Connection accepted on port {port}"); Some(vsock) }, - Err(e) => { - error!("Failed to accept a vsock: {}", e); + Err(err) => { + error!("Failed to accept a vsock: {err}"); None } } @@ -53,18 +53,18 @@ pub fn tls_serve(port: u32, tls_config: Arc) -> Result { - info!("Connection accepted"); + debug!("Connection accepted on port {port}"); match acceptor.accept(vsock).await { Ok(vsock) => Some(vsock), - Err(e) => { - error!("TLS handshake failed: {}", e); + Err(err) => { + error!("TLS handshake failed: {err}"); None } } }, - Err(e) => { - error!("Failed to accept a vsock: {}", e); + Err(err) => { + error!("Failed to accept a vsock: {err}"); None } }