Add proxy tunnel diagnostics and default logging

apps/aether-proxy/src/tunnel/client.rs

@@ -8,7 +8,7 @@ use tokio::sync::watch;
 use tokio_tungstenite::tungstenite::client::IntoClientRequest;
 use tokio_tungstenite::tungstenite::http;
 use tokio_tungstenite::tungstenite::protocol::WebSocketConfig;
-use tracing::{debug, warn};
+use tracing::{debug, info, warn};
 
 use crate::egress_proxy::{connect_target_via_proxy, ProxyConnectOptions, UpstreamProxyConfig};
 use crate::state::{AppState, ServerContext};
@@ -224,9 +224,30 @@ pub async fn connect_and_run(
         let _ = tokio::time::timeout(Duration::from_secs(35), writer_handle).await;
     }
 
-    server
-        .tunnel_metrics
-        .record_disconnect(connected_at.elapsed());
+    let connected_for = connected_at.elapsed();
+    match &outcome {
+        Ok(TunnelOutcome::Shutdown) => info!(
+            conn = conn_idx,
+            connected_duration_ms = connected_for.as_millis() as u64,
+            close_reason = "shutdown",
+            "tunnel session ending"
+        ),
+        Ok(TunnelOutcome::Disconnected) => info!(
+            conn = conn_idx,
+            connected_duration_ms = connected_for.as_millis() as u64,
+            close_reason = "disconnected",
+            "tunnel session ending"
+        ),
+        Err(error) => warn!(
+            conn = conn_idx,
+            connected_duration_ms = connected_for.as_millis() as u64,
+            close_reason = "error",
+            error = %error,
+            "tunnel session ending"
+        ),
+    }
+
+    server.tunnel_metrics.record_disconnect(connected_for);
 
     debug!("tunnel disconnected");
     outcome
@@ -250,14 +271,26 @@ fn spawn_drain_signal(
         }
 
         debug!(conn = conn_idx, "sending GOAWAY for tunnel drain");
-        let _ = tokio::time::timeout(
+        match tokio::time::timeout(
             Duration::from_millis(250),
             frame_tx.send(super::protocol::Frame::control(
                 super::protocol::MsgType::GoAway,
                 bytes::Bytes::new(),
             )),
         )
-        .await;
+        .await
+        {
+            Ok(Ok(())) => info!(conn = conn_idx, "sent GOAWAY for tunnel drain"),
+            Ok(Err(error)) => warn!(
+                conn = conn_idx,
+                error = ?error,
+                "failed to queue GOAWAY for tunnel drain"
+            ),
+            Err(_) => warn!(
+                conn = conn_idx,
+                "timed out queueing GOAWAY for tunnel drain"
+            ),
+        }
     })
 }
 

apps/aether-proxy/src/tunnel/heartbeat.rs

@@ -536,6 +536,10 @@ mod tests {
             .pointer("/proxy_metadata/recent_tunnel_errors/0")
             .and_then(serde_json::Value::as_object)
             .expect("recent tunnel error should be reported");
+        assert!(recent_error
+            .get("timestamp_unix_ms")
+            .and_then(serde_json::Value::as_u64)
+            .is_some());
         assert_eq!(
             recent_error
                 .get("component")

apps/aether-proxy/src/tunnel/writer.rs

@@ -179,10 +179,20 @@ async fn write_frame<S>(sink: &mut S, frame: Frame, tunnel_metrics: Option<&Tunn
 where
     S: SinkExt<Message, Error = tokio_tungstenite::tungstenite::Error> + Unpin + Send + 'static,
 {
+    let stream_id = frame.stream_id;
+    let msg_type = frame.msg_type;
+    let flags = frame.flags;
     let data = frame.encode();
     let wire_len = data.len().max(HEADER_SIZE);
     if let Err(e) = sink.send(Message::Binary(data.into())).await {
-        error!(error = %e, "failed to write frame to WebSocket");
+        error!(
+            stream_id = stream_id,
+            msg_type = ?msg_type,
+            flags = flags,
+            wire_len = wire_len,
+            error = %e,
+            "failed to write frame to WebSocket"
+        );
         if let Some(metrics) = tunnel_metrics {
             metrics.record_error("ws_write_error", &e.to_string());
         }