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();