From c39ff666ede2c58fb9f8831c212c2036915b4f2e Mon Sep 17 00:00:00 2001 From: Bryan Helmkamp Date: Wed, 6 May 2026 12:41:52 -0400 Subject: [PATCH] fix(server): default foreground logs to stdout Keep daemon and hidden serve logs on the file destination by default, while making foreground server commands stream logs to the terminal unless the server config explicitly selects file logging. --- docs/internal/logging-strategy.md | 2 +- .../administration/server-configuration.mdx | 6 +- .../src/commands/server/foreground.rs | 3 + .../fabro-cli/src/commands/server/mod.rs | 1 + .../fabro-cli/src/commands/server/start.rs | 19 ++- lib/crates/fabro-cli/src/main.rs | 113 +++++++++++++++++- .../fabro-cli/tests/it/cmd/server_start.rs | 112 ++++++++++++++++- lib/crates/fabro-install/src/lib.rs | 14 +++ lib/crates/fabro-server/src/serve.rs | 45 +++++-- lib/crates/fabro-server/tests/it/api/tcp.rs | 1 + 10 files changed, 297 insertions(+), 19 deletions(-) diff --git a/docs/internal/logging-strategy.md b/docs/internal/logging-strategy.md index 35ac6f84c..4968d2763 100644 --- a/docs/internal/logging-strategy.md +++ b/docs/internal/logging-strategy.md @@ -1,6 +1,6 @@ # Fabro Logging Strategy -Fabro uses the `tracing` crate for structured logging. CLI logs write to `~/.fabro/logs/cli.YYYY-MM-DD.log`, rotated daily by `tracing-appender`; logs older than 7 days are cleaned up on startup. By default the server writes one main log at `/logs/server.log`, and worker subprocesses append their tracing events to that same file. Set `[server.logging].destination = "stdout"` (or `FABRO_LOG_DESTINATION=stdout`) to stream the server log to stdout instead — required for container deployments where the platform captures stdout. +Fabro uses the `tracing` crate for structured logging. CLI logs write to `~/.fabro/logs/cli.YYYY-MM-DD.log`, rotated daily by `tracing-appender`; logs older than 7 days are cleaned up on startup. Daemonized server starts write one main log at `/logs/server.log` by default. Foreground server starts (`fabro server start --foreground` and `fabro server restart --foreground`) stream server logs to stdout by default when `[server.logging].destination` is absent. Set `[server.logging].destination = "file"` to force file logging, or `FABRO_LOG_DESTINATION=stdout` to force stdout where compatible. Default install-generated `settings.toml` intentionally omits `[server.logging].destination` so foreground mode can use its stdout default. Each worker also writes its tracing events to the run-scoped log at `/runtime/server.log`. This per-run file is worker tracing only: parent-side scheduling/cancel/delete events stay in the main server log, and unstructured worker stderr is still drained by the parent into `/logs/server.log`. diff --git a/docs/public/administration/server-configuration.mdx b/docs/public/administration/server-configuration.mdx index a2ad8d0d2..5c41b7434 100644 --- a/docs/public/administration/server-configuration.mdx +++ b/docs/public/administration/server-configuration.mdx @@ -239,11 +239,11 @@ Configure the server log level and destination. | Key | Description | Default | |---|---|---| | `level` | Log level: `error`, `warn`, `info`, `debug`, `trace` | `"info"` | -| `destination` | Where server logs are written: `file` (rotated daily under `/logs/`) or `stdout` | `"file"` | +| `destination` | Where server logs are written: `file` (rotated daily under `/logs/`) or `stdout` | Daemon: `"file"`; foreground: `"stdout"` | Level precedence: `FABRO_LOG` env var > `--debug` flag > `[server.logging].level` > `"info"`. -Destination precedence: `FABRO_LOG_DESTINATION` env var > `[server.logging].destination` > `"file"`. `stdout` is incompatible with daemon mode — use `fabro server start --foreground` (which is what container images do). +Destination precedence: `FABRO_LOG_DESTINATION` env var > `[server.logging].destination` > command-mode default. `stdout` is incompatible with daemon mode — use `fabro server start --foreground` (which is what container images do). Default install-generated `settings.toml` omits `destination` so foreground mode streams logs to stdout without extra config. The CLI has its own `[cli.logging]` section. @@ -409,4 +409,4 @@ Fabro resolves these from `process env -> server.env`. | Variable | Default | Description | |---|---|---| | `FABRO_LOG` | `info` | Log level: `error`, `warn`, `info`, `debug` | -| `FABRO_LOG_DESTINATION` | `file` | Server log destination: `file` or `stdout` (containers default to `stdout`) | +| `FABRO_LOG_DESTINATION` | Command-mode default | Server log destination: `file` or `stdout` | diff --git a/lib/crates/fabro-cli/src/commands/server/foreground.rs b/lib/crates/fabro-cli/src/commands/server/foreground.rs index 9e7303cd1..b5ae81924 100644 --- a/lib/crates/fabro-cli/src/commands/server/foreground.rs +++ b/lib/crates/fabro-cli/src/commands/server/foreground.rs @@ -6,6 +6,7 @@ use fabro_config::bind::BindRequest; use fabro_config::daemon::ServerDaemon; use fabro_server::serve; use fabro_server::serve::ServeArgs; +use fabro_types::settings::LogDestination; use fabro_util::terminal::Styles; /// Run `serve::serve_command` with scopeguards that write/remove the server @@ -16,6 +17,7 @@ pub(crate) async fn serve_with_daemon_record( bind: BindRequest, storage_dir: PathBuf, styles: &'static Styles, + effective_log_destination: Option, ) -> Result<()> { serve_args.bind = Some(bind.to_string()); @@ -41,6 +43,7 @@ pub(crate) async fn serve_with_daemon_record( serve_args, styles, Some(storage_dir), + effective_log_destination, move |resolved_bind| { ServerDaemon::new(pid, resolved_bind.clone(), log_path.clone()).write(&daemon_dir) }, diff --git a/lib/crates/fabro-cli/src/commands/server/mod.rs b/lib/crates/fabro-cli/src/commands/server/mod.rs index 939af1cc4..e7f4982c4 100644 --- a/lib/crates/fabro-cli/src/commands/server/mod.rs +++ b/lib/crates/fabro-cli/src/commands/server/mod.rs @@ -154,6 +154,7 @@ pub(crate) async fn dispatch( bind_addr, storage_dir, styles, + None, )) .await } diff --git a/lib/crates/fabro-cli/src/commands/server/start.rs b/lib/crates/fabro-cli/src/commands/server/start.rs index e83fabe51..6d42ed1cf 100644 --- a/lib/crates/fabro-cli/src/commands/server/start.rs +++ b/lib/crates/fabro-cli/src/commands/server/start.rs @@ -28,7 +28,8 @@ const SERVER_START_HEALTH_PROBE_TIMEOUT: Duration = Duration::from_millis(250); pub(crate) struct ForegroundServerLogBootstrap { #[expect(dead_code, reason = "held for its Drop to release the server lock")] - lock_file: std::fs::File, + lock_file: std::fs::File, + pub(crate) destination: LogDestination, } pub(crate) async fn execute( @@ -89,7 +90,10 @@ pub(crate) async fn prepare_foreground_server_log( .with_context(|| format!("creating server log file {}", log_path.display()))?; } - Ok(ForegroundServerLogBootstrap { lock_file }) + Ok(ForegroundServerLogBootstrap { + lock_file, + destination, + }) } pub(crate) async fn ensure_server_running_for_storage( @@ -234,11 +238,18 @@ async fn execute_foreground( bind: BindRequest, serve_args: ServeArgs, storage_dir: PathBuf, - _log_bootstrap: ForegroundServerLogBootstrap, + log_bootstrap: ForegroundServerLogBootstrap, styles: &'static Styles, _printer: Printer, ) -> Result<()> { - super::foreground::serve_with_daemon_record(serve_args, bind, storage_dir, styles).await + super::foreground::serve_with_daemon_record( + serve_args, + bind, + storage_dir, + styles, + Some(log_bootstrap.destination), + ) + .await } // --------------------------------------------------------------------------- diff --git a/lib/crates/fabro-cli/src/main.rs b/lib/crates/fabro-cli/src/main.rs index ca413f2db..82bffe02e 100644 --- a/lib/crates/fabro-cli/src/main.rs +++ b/lib/crates/fabro-cli/src/main.rs @@ -477,8 +477,15 @@ async fn prepare_server_bootstrap( let local_config = local_server::LocalServerConfig::load(config_path, storage_dir)?; let storage_dir = local_config.storage_dir().to_path_buf(); let runtime_directory = fabro_config::RuntimeDirectory::new(storage_dir.clone()); + let default_log_destination = if foreground { + LogDestination::Stdout + } else { + LogDestination::File + }; let log_destination = fabro_config::resolve_log_destination( - local_config.config_log_destination().unwrap_or_default(), + local_config + .config_log_destination() + .unwrap_or(default_log_destination), )?; let foreground_server_log_bootstrap = if foreground { Some( @@ -554,6 +561,19 @@ mod tests { write_test_settings_with_logging(path, "warn", "stdout"); } + fn write_test_settings_without_log_destination(path: &std::path::Path) { + std::fs::write( + path, + r#" +_version = 1 + +[server.logging] +level = "warn" +"#, + ) + .unwrap(); + } + fn write_test_settings_with_logging(path: &std::path::Path, level: &str, destination: &str) { std::fs::write( path, @@ -741,6 +761,37 @@ destination = "{destination}" assert!(bootstrap.foreground_server_log_bootstrap.is_some()); } + #[test] + fn pre_tracing_bootstrap_defaults_foreground_start_to_stdout() { + let storage_dir = tempfile::tempdir().unwrap(); + let config_dir = tempfile::tempdir().unwrap(); + let config_path = config_dir.path().join("settings.toml"); + write_test_settings_without_log_destination(&config_path); + + let cli = Cli::try_parse_from([ + "fabro", + "server", + "start", + "--foreground", + "--storage-dir", + storage_dir.path().to_str().unwrap(), + "--config", + config_path.to_str().unwrap(), + ]) + .expect("should parse"); + let command = cli.command.as_deref().unwrap(); + + let bootstrap = runtime() + .block_on(pre_tracing_bootstrap(command)) + .expect("bootstrap should resolve"); + + assert_eq!(bootstrap.sink, logging::InternalLogSink::Server { + log: logging::LogSink::Stdout, + }); + assert_eq!(bootstrap.config_log_level.as_deref(), Some("warn")); + assert!(bootstrap.foreground_server_log_bootstrap.is_some()); + } + #[test] fn pre_tracing_bootstrap_uses_server_sink_for_server_restart_foreground() { let storage_dir = tempfile::tempdir().unwrap(); @@ -772,6 +823,37 @@ destination = "{destination}" assert!(bootstrap.foreground_server_log_bootstrap.is_some()); } + #[test] + fn pre_tracing_bootstrap_explicit_file_keeps_foreground_start_on_file() { + let storage_dir = tempfile::tempdir().unwrap(); + let config_dir = tempfile::tempdir().unwrap(); + let config_path = config_dir.path().join("settings.toml"); + write_test_settings_with_logging(&config_path, "warn", "file"); + + let cli = Cli::try_parse_from([ + "fabro", + "server", + "start", + "--foreground", + "--storage-dir", + storage_dir.path().to_str().unwrap(), + "--config", + config_path.to_str().unwrap(), + ]) + .expect("should parse"); + let command = cli.command.as_deref().unwrap(); + + let bootstrap = runtime() + .block_on(pre_tracing_bootstrap(command)) + .expect("bootstrap should resolve"); + + assert_eq!(bootstrap.sink, logging::InternalLogSink::Server { + log: logging::LogSink::File(storage_dir.path().join("logs").join("server.log")), + }); + assert_eq!(bootstrap.config_log_level.as_deref(), Some("warn")); + assert!(bootstrap.foreground_server_log_bootstrap.is_some()); + } + #[test] fn pre_tracing_bootstrap_uses_server_sink_for_server_serve() { let storage_dir = tempfile::tempdir().unwrap(); @@ -801,6 +883,35 @@ destination = "{destination}" assert!(bootstrap.foreground_server_log_bootstrap.is_none()); } + #[test] + fn pre_tracing_bootstrap_defaults_server_serve_to_file() { + let storage_dir = tempfile::tempdir().unwrap(); + let config_dir = tempfile::tempdir().unwrap(); + let config_path = config_dir.path().join("settings.toml"); + write_test_settings_without_log_destination(&config_path); + let cli = Cli::try_parse_from([ + "fabro", + "server", + "__serve", + "--storage-dir", + storage_dir.path().to_str().unwrap(), + "--config", + config_path.to_str().unwrap(), + ]) + .expect("should parse"); + let command = cli.command.as_deref().unwrap(); + + let bootstrap = runtime() + .block_on(pre_tracing_bootstrap(command)) + .expect("bootstrap should resolve"); + + assert_eq!(bootstrap.sink, logging::InternalLogSink::Server { + log: logging::LogSink::File(storage_dir.path().join("logs").join("server.log")), + }); + assert_eq!(bootstrap.config_log_level.as_deref(), Some("warn")); + assert!(bootstrap.foreground_server_log_bootstrap.is_none()); + } + #[test] fn pre_tracing_bootstrap_env_destination_overrides_config_file() { let storage_dir = tempfile::tempdir().unwrap(); diff --git a/lib/crates/fabro-cli/tests/it/cmd/server_start.rs b/lib/crates/fabro-cli/tests/it/cmd/server_start.rs index ff8f76813..86c928f4b 100644 --- a/lib/crates/fabro-cli/tests/it/cmd/server_start.rs +++ b/lib/crates/fabro-cli/tests/it/cmd/server_start.rs @@ -150,8 +150,8 @@ fn run_startup_failure(context: &TestContext, mode: ServerStartMode, case: &Star let log_path = storage_dir.join("logs/server.log"); match mode { ServerStartMode::Foreground => assert!( - log_path.exists(), - "foreground validation intentionally runs after log bootstrap for {}", + !log_path.exists(), + "foreground stdout bootstrap should fail before creating server.log for {}", case.name ), ServerStartMode::Daemon => assert!( @@ -418,7 +418,7 @@ fn start_without_default_settings_reports_missing_web_assets_for_browser_install clippy::disallowed_methods, reason = "This sync integration test spawns the real foreground server process to verify log ownership." )] -fn foreground_start_writes_tracing_to_storage_server_log() { +fn foreground_start_writes_tracing_to_stdout_by_default() { let home_dir = tempfile::tempdir_in("/tmp").unwrap(); let storage_root = isolated_storage_dir(); let storage_dir = storage_root.path().join("storage"); @@ -431,6 +431,112 @@ fn foreground_start_writes_tracing_to_storage_server_log() { std::fs::create_dir_all(storage_log_path.parent().unwrap()).unwrap(); std::fs::write(&storage_log_path, "stale pre-start log entry\n").unwrap(); + let mut cmd = std::process::Command::new(env!("CARGO_BIN_EXE_fabro")); + apply_test_isolation(&mut cmd, home_dir.path()); + cmd.args(["server", "start", "--foreground"]) + .arg("--storage-dir") + .arg(&storage_dir) + .arg("--bind") + .arg(&socket_path) + .arg("--config") + .arg(&config_path) + .stdin(Stdio::null()) + .stdout(Stdio::piped()) + .stderr(Stdio::piped()); + + let mut child = cmd.spawn().expect("server start should spawn"); + let record_path = storage_dir.join("server.json"); + let deadline = Instant::now() + Duration::from_secs(5); + + while Instant::now() < deadline { + if record_path.exists() { + break; + } + if let Some(status) = child.try_wait().expect("server start should poll") { + let output = child + .wait_with_output() + .expect("server start output should be readable"); + panic!( + "foreground server exited before writing server.json with status {status}:\nstderr:\n{}", + String::from_utf8_lossy(&output.stderr) + ); + } + std::thread::sleep(Duration::from_millis(50)); + } + + assert!( + record_path.exists(), + "expected foreground start to create server.json" + ); + + let stop_output = { + let mut stop = std::process::Command::new(env!("CARGO_BIN_EXE_fabro")); + apply_test_isolation(&mut stop, home_dir.path()); + stop.args(["server", "stop"]) + .arg("--storage-dir") + .arg(&storage_dir) + .output() + .expect("server stop should run") + }; + assert!( + stop_output.status.success(), + "server stop should succeed:\nstdout:\n{}\nstderr:\n{}", + String::from_utf8_lossy(&stop_output.stdout), + String::from_utf8_lossy(&stop_output.stderr) + ); + + let output = child + .wait_with_output() + .expect("server start output should be readable"); + let stdout = String::from_utf8_lossy(&output.stdout); + assert!( + stdout.contains("API server started"), + "expected foreground stdout to contain server tracing, got:\n{stdout}\nforeground stderr:\n{}", + String::from_utf8_lossy(&output.stderr) + ); + assert!( + stdout.contains("Shutdown signal received, stopping server"), + "expected foreground stdout to contain shutdown tracing, got:\n{stdout}" + ); + assert!( + stdout.find("API server started") + < stdout.find("Shutdown signal received, stopping server"), + "expected shutdown trace to append after startup trace, got:\n{stdout}", + ); + let storage_log = std::fs::read_to_string(&storage_log_path).unwrap_or_default(); + assert_eq!(storage_log, "stale pre-start log entry\n"); + + let home_server_logs = server_log_files(&home_dir.path().join(".fabro").join("logs")); + assert!( + home_server_logs.is_empty(), + "expected foreground server start to avoid home server logs, found: {home_server_logs:?}" + ); +} + +#[test] +#[expect( + clippy::disallowed_methods, + reason = "This sync integration test spawns the real foreground server process to verify log ownership." +)] +fn foreground_start_with_file_destination_writes_tracing_to_storage_server_log() { + let home_dir = tempfile::tempdir_in("/tmp").unwrap(); + let storage_root = isolated_storage_dir(); + let storage_dir = storage_root.path().join("storage"); + let socket_path = storage_root.path().join("foreground-file.sock"); + let config_dir = tempfile::tempdir_in("/tmp").unwrap(); + let config_path = config_dir.path().join("settings.toml"); + write_dev_token_server_settings( + &config_path, + r#" +[server.logging] +destination = "file" +"#, + ); + provision_dev_token_auth(home_dir.path(), &storage_dir); + let storage_log_path = storage_dir.join("logs").join("server.log"); + std::fs::create_dir_all(storage_log_path.parent().unwrap()).unwrap(); + std::fs::write(&storage_log_path, "stale pre-start log entry\n").unwrap(); + let mut cmd = std::process::Command::new(env!("CARGO_BIN_EXE_fabro")); apply_test_isolation(&mut cmd, home_dir.path()); cmd.args(["server", "start", "--foreground"]) diff --git a/lib/crates/fabro-install/src/lib.rs b/lib/crates/fabro-install/src/lib.rs index 97463f7e9..cc2256482 100644 --- a/lib/crates/fabro-install/src/lib.rs +++ b/lib/crates/fabro-install/src/lib.rs @@ -556,6 +556,20 @@ mod tests { assert_eq!(cfg.server.auth.methods, vec![ServerAuthMethod::DevToken]); } + #[test] + fn config_toml_omits_server_logging_destination() { + let toml_str = format_config_toml(); + let cfg: toml::Value = toml::from_str(&toml_str).expect("generated config should parse"); + let destination = cfg + .get("server") + .and_then(toml::Value::as_table) + .and_then(|server| server.get("logging")) + .and_then(toml::Value::as_table) + .and_then(|logging| logging.get("destination")); + + assert_eq!(destination, None); + } + #[test] fn merge_server_settings_preserves_existing_top_level_sections() { let mut doc: toml::Value = toml::from_str( diff --git a/lib/crates/fabro-server/src/serve.rs b/lib/crates/fabro-server/src/serve.rs index c3de8df7a..4f0f26ea4 100644 --- a/lib/crates/fabro-server/src/serve.rs +++ b/lib/crates/fabro-server/src/serve.rs @@ -14,7 +14,7 @@ use fabro_install::{OBJECT_STORE_ACCESS_KEY_ID_ENV, OBJECT_STORE_SECRET_ACCESS_K use fabro_sandbox::SandboxProvider; use fabro_static::EnvVars; use fabro_types::ServerSettings; -use fabro_types::settings::server::{GithubIntegrationStrategy, WebhookStrategy}; +use fabro_types::settings::server::{GithubIntegrationStrategy, LogDestination, WebhookStrategy}; use fabro_types::settings::{ GithubIntegrationSettings, InterpString, ObjectStoreSettings, ServerListenSettings, ServerNamespace, @@ -500,6 +500,15 @@ pub fn resolve_runtime_server_settings_for_start( Ok(resolved.server_settings.server) } +fn apply_effective_log_destination( + settings: &mut ServerSettings, + destination: Option, +) { + if let Some(destination) = destination { + settings.server.logging.destination = destination; + } +} + pub fn resolve_bind_request_from_server_settings( settings: &ServerSettings, explicit_bind: Option<&str>, @@ -603,6 +612,7 @@ pub async fn serve_command( args: ServeArgs, styles: &'static Styles, storage_dir_override: Option, + effective_log_destination: Option, mut on_ready: F, ) -> anyhow::Result<()> where @@ -632,6 +642,10 @@ where runtime_settings.server_settings = runtime_settings .server_settings .with_storage_override(&data_dir); + apply_effective_log_destination( + &mut runtime_settings.server_settings, + effective_log_destination, + ); let resolved_app_settings = ResolvedAppStateSettings { server_settings: runtime_settings.server_settings, manifest_run_defaults: runtime_settings.manifest_run_defaults, @@ -1114,15 +1128,16 @@ mod tests { use fabro_config::{RunSettingsBuilder, ServerSettingsBuilder}; use fabro_types::ServerSettings; use fabro_types::settings::interp::InterpString; - use fabro_types::settings::server::ObjectStoreSettings; + use fabro_types::settings::server::{LogDestination, ObjectStoreSettings}; use fabro_util::Home; use super::{ - GitHubMetaResolver, ServeArgs, ServerTitlePhase, bind_tcp_host_with_fallback, - build_local_object_store_with_preference, build_object_store_from_settings_with_lookup, - build_slatedb_store, resolve_bind_request_from_server_settings, - resolve_github_webhook_ip_allowlist, resolve_startup_github_webhook_ip_allowlist, - serve_overrides, server_bind_title, server_title, + GitHubMetaResolver, ServeArgs, ServerTitlePhase, apply_effective_log_destination, + bind_tcp_host_with_fallback, build_local_object_store_with_preference, + build_object_store_from_settings_with_lookup, build_slatedb_store, + resolve_bind_request_from_server_settings, resolve_github_webhook_ip_allowlist, + resolve_startup_github_webhook_ip_allowlist, serve_overrides, server_bind_title, + server_title, }; use crate::server::ResolvedAppStateSettings; @@ -1217,6 +1232,22 @@ root = "/srv/from-disk" ); } + #[test] + fn effective_log_destination_overrides_resolved_server_settings() { + let mut settings = server_settings( + r#" +_version = 1 + +[server.logging] +destination = "file" +"#, + ); + + apply_effective_log_destination(&mut settings, Some(LogDestination::Stdout)); + + assert_eq!(settings.server.logging.destination, LogDestination::Stdout); + } + #[test] fn apply_runtime_settings_enables_web_from_cli_flag() { let args = ServeArgs { diff --git a/lib/crates/fabro-server/tests/it/api/tcp.rs b/lib/crates/fabro-server/tests/it/api/tcp.rs index 9b2703aa3..7c0f2a79d 100644 --- a/lib/crates/fabro-server/tests/it/api/tcp.rs +++ b/lib/crates/fabro-server/tests/it/api/tcp.rs @@ -93,6 +93,7 @@ async fn spawn_served_listener( }, styles, Some(storage_dir), + None, move |bind| { let sender = tx.take().expect("server should only report readiness once"); sender.send(bind.clone()).ok();