jetsocat: clarify logs

jetsocat/src/main.rs

@@ -33,13 +33,29 @@ fn main() {
 }
 
 fn generate_usage() -> String {
+    #[cfg(debug_assertions)]
+    const IS_DEBUG: bool = true;
+    #[cfg(not(debug_assertions))]
+    const IS_DEBUG: bool = false;
+    #[cfg(feature = "verbose")]
+    const IS_VERBOSE: bool = true;
+    #[cfg(not(feature = "verbose"))]
+    const IS_VERBOSE: bool = false;
+
     format!(
         "{command} [action]\n\
         \n\
-        \tExample: unauthenticated powershell\n\
+        \tExample: unauthenticated PowerShell\n\
+        \n\
+        \t  {command} listen 127.0.0.1:5002 --cmd 'pwsh -sshs -NoLogo -NoProfile'\n\
         \n\
-        \t  {command} listen 127.0.0.1:5002 --cmd 'pwsh -sshs -NoLogo -NoProfile'",
-        command = env!("CARGO_PKG_NAME")
+        For detailed logs use debug binary or any binary built with 'verbose' feature enabled.\n\
+        This binary was built as:\n\
+        \tDebug? {is_debug}\n\
+        \tVerbose? {is_verbose}",
+        command = env!("CARGO_PKG_NAME"),
+        is_debug = IS_DEBUG,
+        is_verbose = IS_VERBOSE,
     )
 }
 
@@ -49,7 +65,7 @@ pub fn run<F: Future<Output = anyhow::Result<()>>>(log: Logger, f: F) -> anyhow:
         .build()
         .context("runtime build failed")?;
     rt.block_on(f)?;
-    info!(log, "Terminated successfuly");
+    info!(log, "Terminated successfully");
     rt.shutdown_timeout(std::time::Duration::from_millis(100)); // just to be safe
     Ok(())
 }
@@ -189,7 +205,7 @@ fn parse_env_variable_as_args(env_var_str: &str) -> Vec<String> {
 
 fn apply_common_flags(cmd: Command) -> Command {
     cmd.flag(Flag::new("log-file", FlagType::String).description("Specify filepath for log file"))
-        .flag(Flag::new("log-term", FlagType::Bool).description("Disable logging"))
+        .flag(Flag::new("log-term", FlagType::Bool).description("Print logs to stdout instead of log file"))
         .flag(Flag::new("no-proxy", FlagType::Bool).description("Disable any form of proxy auto-detection"))
         .flag(Flag::new("socks4", FlagType::String).description("Use specificed address:port as SOCKS4 proxy"))
         .flag(Flag::new("socks5", FlagType::String).description("Use specificed address:port as SOCKS5 proxy"))

jetsocat/src/tcp_proxy.rs

@@ -4,7 +4,7 @@ use anyhow::{anyhow, Context as _, Result};
 use futures_util::FutureExt;
 use jet_proto::JET_VERSION_V2;
 use jetsocat_proxy::{DestAddr, ToDestAddr};
-use slog::{debug, o, Logger};
+use slog::{debug, info, o, warn, Logger};
 use tokio::pin;
 use uuid::Uuid;
 
@@ -44,23 +44,29 @@ impl TcpServer {
     }
 
     pub async fn serve(self, log: Logger) -> Result<()> {
-        debug!(log, "Performing rendezvous connect...");
+        info!(log, "Performing rendezvous connect...");
 
-        for _ in 0..=self.max_reconnection_count {
+        debug!(
+            log,
+            "Up to {} reconnection(s) are allowed (at most {} connection(s))",
+            self.max_reconnection_count,
+            self.max_reconnection_count + 1
+        );
+
+        for i in 0..=self.max_reconnection_count {
             let mut jet_server_stream = tcp_connect_async(&self.jet_listener_addr, self.proxy_cfg.clone()).await?;
             // forward_addr points to local machine/network, proxy should be ignored
             let server_stream = tcp_connect_async(&self.forward_addr, None).await?;
 
-            let log = log.clone();
-
-            debug!(log, "Sending jet accept request...");
-
+            debug!(log, "Sending JetAcceptReq...");
             self.send_jet_accept_request(&mut jet_server_stream).await?;
+            debug!(log, "JetAcceptReq sent!");
             self.process_jet_accept_response(&mut jet_server_stream).await?;
+            debug!(log, "JetAcceptRsp received and processed successfully!");
 
-            debug!(log, "Starting tcp forwarding...");
+            info!(log, "Successful rendezvous connect ({})", i);
 
-            run_proxy(jet_server_stream, server_stream, log).await?;
+            run_proxy(jet_server_stream, server_stream, log.clone()).await?;
         }
 
         Ok(())
@@ -94,21 +100,24 @@ impl TcpServer {
         let read_bytes_count = jet_server_stream.read(&mut buffer).await?;
 
         if read_bytes_count == 0 {
-            return Err(anyhow!("Failed to read JetConnectResponse"));
+            return Err(anyhow!("Failed to read JetConnectRsp"));
         }
 
         let mut buffer: &[u8] = &buffer[0..read_bytes_count];
         let response = JetMessage::read_accept_response(&mut buffer)?;
         match response {
             JetMessage::JetAcceptRsp(rsp) => {
                 if rsp.status_code != 200 {
-                    return Err(anyhow!("Devolutions-Gateway sent bad accept response"));
+                    return Err(anyhow!(
+                        "received JetAcceptRsp with unexpected status code from Devolutions-Gateway ({})",
+                        rsp.status_code
+                    ));
                 }
                 Ok(())
             }
             other_message => {
                 return Err(anyhow!(
-                    "Devolutions-Gateway sent {:?} message instead of JetAcceptRsp",
+                    "received {:?} message from Devolutions-Gateway instead of JetAcceptRsp",
                     other_message
                 ))
             }
@@ -120,13 +129,13 @@ async fn run_proxy(jet_server_stream: AsyncStream, tcp_server_transport: AsyncSt
     use crate::io::read_and_write;
     use futures_util::select;
 
-    debug!(log, "{}", "Running jet tcp proxy");
+    info!(log, "{}", "Running jet TCP proxy");
 
     let (mut client_read_half, mut client_write_half) = tokio::io::split(jet_server_stream);
     let (mut server_read_half, mut server_write_half) = tokio::io::split(tcp_server_transport);
 
-    let client_server_logger = log.new(o!("client" => " -> server"));
-    let server_client_logger = log.new(o!("client" => " <- server"));
+    let client_server_logger = log.new(o!("client" => " → server"));
+    let server_client_logger = log.new(o!("client" => " ← server"));
 
     let client_to_server = read_and_write(&mut client_read_half, &mut server_write_half, client_server_logger).fuse();
     let server_to_client = read_and_write(&mut server_read_half, &mut client_write_half, server_client_logger).fuse();
@@ -137,20 +146,20 @@ async fn run_proxy(jet_server_stream: AsyncStream, tcp_server_transport: AsyncSt
         result = client_to_server => {
             match result {
                 Ok(()) =>  {
-                    debug!(log, "client_to_server disconnected gracefully");
+                    info!(log, "client → server stream ended gracefully");
                 }
                 Err(e) => {
-                    debug!(log, "client_to_server disconnected with error: {}", e);
+                    warn!(log, "client → server stream ended with error: {}", e);
                 }
             }
         },
         result = server_to_client => {
             match result {
                 Ok(()) =>  {
-                    debug!(log, "server_to_client disconnected gracefully");
+                    info!(log, "client ← server stream ended gracefully");
                 }
                 Err(e) => {
-                    debug!(log, "server_to_client disconnected with error: {}", e);
+                    warn!(log, "client ← server stream ended with error: {}", e);
                 }
             }
         },