feat: logging for the goose-acp server + --server fix

alexhancock · alexhancock · commit 199883cb47c5 · 2026-04-16T14:55:15.000-04:00
diff --git a/Cargo.lock b/Cargo.lock
diff --git a/crates/goose-acp/Cargo.toml b/crates/goose-acp/Cargo.toml
@@ -41,7 +41,7 @@ url = { workspace = true }
 # HTTP server dependencies
 axum = { workspace = true, features = ["ws"] }
 serde = { workspace = true, features = ["derive"] }
-tower-http = { workspace = true, features = ["cors"] }
+tower-http = { workspace = true, features = ["cors", "trace"] }
 async-stream = { workspace = true }
 http-body-util = "0.1.3"
 uuid = { workspace = true, features = ["v7"] }
diff --git a/crates/goose-acp/src/transport.rs b/crates/goose-acp/src/transport.rs
@@ -16,6 +16,7 @@ use axum::{
 };
 use serde_json::Value;
 use tower_http::cors::{Any, CorsLayer};
+use tower_http::trace::TraceLayer;
 
 use crate::server_factory::AcpServer;
 
@@ -145,5 +146,6 @@ pub fn create_router(server: Arc<AcpServer>) -> Router {
             get(handle_get).with_state((http_state.clone(), ws_state)),
         )
         .route("/acp", delete(http::handle_delete).with_state(http_state))
+        .layer(TraceLayer::new_for_http())
         .layer(cors)
 }
diff --git a/crates/goose-acp/src/transport/http.rs b/crates/goose-acp/src/transport/http.rs
@@ -216,6 +216,21 @@ async fn run_router(
     router: Arc<MessageRouter>,
 ) {
     while let Some(msg) = from_agent_rx.recv().await {
+        if let Ok(parsed) = serde_json::from_str::<Value>(&msg) {
+            let method = parsed
+                .get("method")
+                .and_then(|m| m.as_str())
+                .unwrap_or("<response>");
+            let id = parsed.get("id").map(|id| id.to_string());
+            if is_jsonrpc_response_or_error(&parsed) {
+                info!(
+                    id = id.as_deref().unwrap_or(""),
+                    "ACP response sent to client"
+                );
+            } else {
+                debug!(method = method, "ACP server notification: {}", method);
+            }
+        }
         router.route(&msg).await;
     }
     debug!("Router task exiting — agent channel closed");
@@ -425,8 +440,18 @@ pub(crate) async fn handle_post(
             .into_response();
     }
 
+    let method = json_message
+        .get("method")
+        .and_then(|m| m.as_str())
+        .unwrap_or("<response>");
+    let rpc_id = json_message
+        .get("id")
+        .map(|id| id.to_string())
+        .unwrap_or_default();
+
     // Initialize — no Acp-Connection-Id required.
     if is_initialize_request(&json_message) {
+        info!(method = method, id = %rpc_id, "ACP request: initialize (new connection)");
         return handle_initialize(state, &json_message).await;
     }
 
@@ -444,9 +469,19 @@ pub(crate) async fn handle_post(
     }
 
     if is_jsonrpc_request(&json_message) {
+        info!(
+            method = method,
+            id = %rpc_id,
+            connection_id = %conn_id,
+            "ACP request: {}", method
+        );
         handle_request(state, &conn_id, &json_message).await
     } else {
-        // Notification or client response — fire and forget.
+        info!(
+            method = method,
+            connection_id = %conn_id,
+            "ACP notification/response: {}", method
+        );
         handle_notification_or_response(state, &conn_id, &json_message).await
     }
 }
diff --git a/crates/goose-acp/src/transport/websocket.rs b/crates/goose-acp/src/transport/websocket.rs
@@ -4,6 +4,7 @@ use axum::{
     response::{IntoResponse, Response},
 };
 use futures::{SinkExt, StreamExt};
+use serde_json::Value;
 use std::{collections::HashMap, sync::Arc};
 use tokio::sync::{mpsc, RwLock};
 use tokio_util::compat::{TokioAsyncReadCompatExt, TokioAsyncWriteCompatExt};
@@ -134,7 +135,10 @@ pub(crate) async fn handle_ws(socket: WebSocket, state: Arc<WsState>, connection
                 match msg_result {
                     Ok(Message::Text(text)) => {
                         let text_str = text.to_string();
-                        debug!(connection_id = %connection_id, "Client → Agent: {} bytes", text_str.len());
+                        if let Ok(parsed) = serde_json::from_str::<Value>(&text_str) {
+                            let method = parsed.get("method").and_then(|m| m.as_str()).unwrap_or("<response>");
+                            info!(connection_id = %connection_id, method = method, "WS client → agent: {}", method);
+                        }
                         if let Err(e) = to_agent.send(text_str).await {
                             error!(connection_id = %connection_id, "Failed to send to agent: {}", e);
                             break;
@@ -157,7 +161,15 @@ pub(crate) async fn handle_ws(socket: WebSocket, state: Arc<WsState>, connection
             }
 
             Some(text) = from_agent_rx.recv() => {
-                debug!(connection_id = %connection_id, "Agent → Client: {} bytes", text.len());
+                if let Ok(parsed) = serde_json::from_str::<Value>(&text) {
+                    let method = parsed.get("method").and_then(|m| m.as_str());
+                    let id = parsed.get("id").map(|id| id.to_string());
+                    if let Some(m) = method {
+                        info!(connection_id = %connection_id, method = m, "WS agent → client: {}", m);
+                    } else if id.is_some() {
+                        info!(connection_id = %connection_id, id = id.as_deref().unwrap_or(""), "WS agent → client: response");
+                    }
+                }
                 if let Err(e) = ws_tx.send(Message::Text(text.into())).await {
                     error!(connection_id = %connection_id, "Failed to send to client: {}", e);
                     break;
diff --git a/crates/goose-cli/src/logging.rs b/crates/goose-cli/src/logging.rs
@@ -28,11 +28,20 @@ fn default_env_filter() -> EnvFilter {
 /// - No console output (all logs go to files only)
 /// - Optional Langfuse integration (DEBUG level)
 pub fn setup_logging(name: Option<&str>) -> Result<()> {
-    setup_logging_internal(name, false)
+    setup_logging_with_options(name, false, false)
 }
 
-/// Internal function that allows bypassing the Once check for testing
-fn setup_logging_internal(name: Option<&str>, force: bool) -> Result<()> {
+/// Sets up logging with console output on stderr.
+/// Used by the `serve` command so operators can see requests arriving.
+pub fn setup_logging_with_console(name: Option<&str>) -> Result<()> {
+    setup_logging_with_options(name, false, true)
+}
+
+fn setup_logging_with_options(name: Option<&str>, force: bool, console: bool) -> Result<()> {
+    setup_logging_internal(name, force, console)
+}
+
+fn setup_logging_internal(name: Option<&str>, force: bool, console: bool) -> Result<()> {
     let mut result = Ok(());
 
     let mut setup = || {
@@ -63,10 +72,23 @@ fn setup_logging_internal(name: Option<&str>, force: bool) -> Result<()> {
                 EnvFilter::try_from_default_env().unwrap_or_else(|_| default_env_filter());
 
             // Start building the subscriber
-            let mut layers = vec![
-                file_layer.with_filter(env_filter).boxed(),
-                // Console logging disabled for CLI - all logs go to files only
-            ];
+            let mut layers = vec![file_layer.with_filter(env_filter).boxed()];
+
+            if console {
+                let console_filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| {
+                    EnvFilter::new("")
+                        .add_directive("goose_acp=info".parse().unwrap())
+                        .add_directive("goose=info".parse().unwrap())
+                        .add_directive("tower_http=info".parse().unwrap())
+                        .add_directive(LevelFilter::WARN.into())
+                });
+                let console_layer = fmt::layer()
+                    .with_target(true)
+                    .with_level(true)
+                    .with_writer(std::io::stderr)
+                    .with_ansi(true);
+                layers.push(console_layer.with_filter(console_filter).boxed());
+            }
 
             #[cfg(feature = "otel")]
             if !force {
diff --git a/crates/goose-cli/src/main.rs b/crates/goose-cli/src/main.rs
@@ -3,7 +3,13 @@ use goose_cli::cli::cli;
 
 #[tokio::main]
 async fn main() -> Result<()> {
-    if let Err(e) = goose_cli::logging::setup_logging(None) {
+    let is_serve = std::env::args().any(|a| a == "serve");
+    let logging_result = if is_serve {
+        goose_cli::logging::setup_logging_with_console(Some("serve"))
+    } else {
+        goose_cli::logging::setup_logging(None)
+    };
+    if let Err(e) = logging_result {
         eprintln!("Warning: Failed to initialize logging: {}", e);
     }
 
diff --git a/crates/goose/src/agents/agent.rs b/crates/goose/src/agents/agent.rs
@@ -1230,7 +1230,6 @@ impl Agent {
                     .unwrap_or(DEFAULT_MAX_TURNS)
             });
             let mut compaction_attempts = 0;
-            let mut last_assistant_text = String::new();
 
             loop {
                 if is_token_cancelled(&cancel_token) {
@@ -1337,10 +1336,6 @@ impl Agent {
 
                                 let num_tool_requests = frontend_requests.len() + remaining_requests.len();
                                 if num_tool_requests == 0 {
-                                    let text = filtered_response.as_concat_text();
-                                    if !text.is_empty() {
-                                        last_assistant_text = text;
-                                    }
                                     messages_to_add.push(response);
                                     continue;
                                 }
@@ -1799,9 +1794,7 @@ impl Agent {
                 tokio::task::yield_now().await;
             }
 
-            if !last_assistant_text.is_empty() {
-                tracing::info!(target: "goose::agents::agent", trace_output = last_assistant_text.as_str());
-            }
+
         }.instrument(reply_stream_span));
         Ok(inner)
     }
diff --git a/ui/text/scripts/dev-start.mjs b/ui/text/scripts/dev-start.mjs
@@ -1,7 +1,7 @@
 #!/usr/bin/env node
 
-// Development entrypoint: ensures a goose binary is available, then launches
-// the TUI via tsx. Skips the cargo build if GOOSE_BINARY is already set.
+// Development entrypoint: ensures a goose binary is available, then launches the TUI
+// Skips the cargo build if GOOSE_BINARY is already set or if --server is provided
 
 import { execFileSync } from "node:child_process";
 import { existsSync } from "node:fs";
@@ -10,8 +10,16 @@ import { fileURLToPath } from "node:url";
 
 const __dirname = dirname(fileURLToPath(import.meta.url));
 const repoRoot = join(__dirname, "..", "..", "..");
-
-if (!process.env.GOOSE_BINARY) {
+const args = process.argv.slice(2);
+const hasServerFlag = args.some(
+  (arg) =>
+    arg === "--server" ||
+    arg === "-s" ||
+    arg.startsWith("--server=") ||
+    arg.startsWith("-s="),
+);
+
+if (!hasServerFlag && !process.env.GOOSE_BINARY) {
   const binName = process.platform === "win32" ? "goose.exe" : "goose";
   const binaryPath = join(repoRoot, "target", "debug", binName);
 

Original file line number	Diff line number	Diff line change
`@@ -16,6 +16,7 @@ use axum::{`
`16`	`16`	`};`
`17`	`17`	`use serde_json::Value;`
`18`	`18`	`use tower_http::cors::{Any, CorsLayer};`
	`19`	`+use tower_http::trace::TraceLayer;`
`19`	`20`
`20`	`21`	`use crate::server_factory::AcpServer;`
`21`	`22`
`@@ -145,5 +146,6 @@ pub fn create_router(server: Arc<AcpServer>) -> Router {`
`145`	`146`	`get(handle_get).with_state((http_state.clone(), ws_state)),`
`146`	`147`	`)`
`147`	`148`	`.route("/acp", delete(http::handle_delete).with_state(http_state))`
	`149`	`+ .layer(TraceLayer::new_for_http())`
`148`	`150`	`.layer(cors)`
`149`	`151`	`}`