diff --git a/backend/windmill-common/src/tracing_init.rs b/backend/windmill-common/src/tracing_init.rs index c0161c8075b73..950f13c18528d 100644 --- a/backend/windmill-common/src/tracing_init.rs +++ b/backend/windmill-common/src/tracing_init.rs @@ -38,6 +38,25 @@ fn compact_layer() -> Layer Targets { + let targets = Targets::new() + .with_target("windmill:job_log", tracing::level_filters::LevelFilter::OFF); + + if *QUIET_MODE { + targets + .with_target(VERBOSE_TARGET, tracing::level_filters::LevelFilter::OFF) + .with_default(default_env_filter) + } else { + targets.with_default(default_env_filter) + } } pub const LOGS_SERVICE: &str = "logs/services/"; @@ -156,22 +175,14 @@ pub fn initialize_tracing( .with_writer(std::io::stdout) .flatten_event(true) .with_filter(stdout_env_filter) - .with_filter( - Targets::new() - .with_target("windmill:job_log", tracing::level_filters::LevelFilter::OFF) - .with_default(default_env_filter), - ); + .with_filter(create_targets_filter(default_env_filter)); // File layer with its own filter let file_layer = json_layer() .with_writer(log_file_writer) .flatten_event(true) .with_filter(file_env_filter) - .with_filter( - Targets::new() - .with_target("windmill:job_log", tracing::level_filters::LevelFilter::OFF) - .with_default(default_env_filter), - ); + .with_filter(create_targets_filter(default_env_filter)); base_layer .with(stdout_layer) @@ -188,11 +199,7 @@ pub fn initialize_tracing( .with_line_number(true) .with_target(false) .with_filter(stdout_env_filter) - .with_filter( - Targets::new() - .with_target("windmill:job_log", tracing::level_filters::LevelFilter::OFF) - .with_default(default_env_filter), - ); + .with_filter(create_targets_filter(default_env_filter)); // File layer with its own filter let file_layer = compact_layer() @@ -202,11 +209,7 @@ pub fn initialize_tracing( .with_line_number(true) .with_target(false) .with_filter(file_env_filter) - .with_filter( - Targets::new() - .with_target("windmill:job_log", tracing::level_filters::LevelFilter::OFF) - .with_default(default_env_filter), - ); + .with_filter(create_targets_filter(default_env_filter)); base_layer .with(stdout_layer) diff --git a/backend/windmill-worker/src/handle_child.rs b/backend/windmill-worker/src/handle_child.rs index 0604ebff051ae..18e053116a4b7 100644 --- a/backend/windmill-worker/src/handle_child.rs +++ b/backend/windmill-worker/src/handle_child.rs @@ -58,6 +58,8 @@ use crate::job_logger_oss::process_streaming_log_lines; use crate::worker_utils::{ping_job_status, update_worker_ping_from_job}; use crate::{MAX_RESULT_SIZE, MAX_WAIT_FOR_SIGINT, MAX_WAIT_FOR_SIGTERM}; +use windmill_common::tracing_init::{QUIET_MODE, VERBOSE_TARGET}; + lazy_static::lazy_static! { pub static ref SLOW_LOGS: bool = std::env::var("SLOW_LOGS").ok().is_some_and(|x| x == "1" || x == "true"); pub static ref OTEL_JOB_LOGS: bool = std::env::var("OTEL_JOB_LOGS").ok().is_some_and(|x| x == "1" || x == "true"); @@ -702,9 +704,11 @@ where tokio::select!( _ = rx.recv() => break, _ = interval.tick() => { - // update the last_ping column every 5 seconds + // update the last_ping column every 5 seconds (or 50 seconds in quiet mode) i+=1; - if i == 1 || i % 10 == 0 { + // In quiet mode, emit memory snapshot logs 10x less frequently + let memory_snapshot_interval = if *QUIET_MODE { 100 } else { 10 }; + if i == 1 || i % memory_snapshot_interval == 0 { let memory_usage = get_worker_memory_usage(); let wm_memory_usage = get_windmill_memory_usage(); tracing::info!("job {job_id} on {worker_name} in {w_id} worker memory snapshot {}kB/{}kB", memory_usage.unwrap_or_default()/1024, wm_memory_usage.unwrap_or_default()/1024); @@ -719,7 +723,11 @@ where if current_mem > *mem_peak { *mem_peak = current_mem } - tracing::info!("job {job_id} on {worker_name} in {w_id} still running. mem: {current_mem}kB, peak mem: {mem_peak}kB"); + // In quiet mode, emit "still running" logs 10x less frequently + let still_running_interval = if *QUIET_MODE { 10 } else { 1 }; + if i % still_running_interval == 0 { + tracing::info!("job {job_id} on {worker_name} in {w_id} still running. mem: {current_mem}kB, peak mem: {mem_peak}kB"); + } let update_job_row = i == 2 || (!*SLOW_LOGS && (i < 20 || (i < 120 && i % 5 == 0) || i % 10 == 0)) || i % 20 == 0; @@ -778,7 +786,7 @@ where }, ); } - tracing::info!("job {job_id} finished"); + tracing::info!(target: VERBOSE_TARGET, "job {job_id} finished"); UpdateJobPollingExit::Done(canceled_by_ref.clone()) } diff --git a/backend/windmill-worker/src/worker.rs b/backend/windmill-worker/src/worker.rs index 36ec01b2fb250..3bf6711a5f2c2 100644 --- a/backend/windmill-worker/src/worker.rs +++ b/backend/windmill-worker/src/worker.rs @@ -77,6 +77,7 @@ use windmill_common::{ flows::FlowNodeId, jobs::JobKind, scripts::{get_full_hub_script_by_path, ScriptHash, ScriptLang}, + tracing_init::{QUIET_MODE, VERBOSE_TARGET}, utils::StripPath, worker::{CLOUD_HOSTED, NO_LOGS, WORKER_CONFIG, WORKER_GROUP}, DB, IS_READY, @@ -1027,7 +1028,7 @@ pub fn start_interactive_worker_shell( match pulled_job { Ok(Some(job)) => { - tracing::debug!(worker = %worker_name, hostname = %hostname, "started handling of job {}", job.id); + tracing::debug!(target: VERBOSE_TARGET, worker = %worker_name, hostname = %hostname, "started handling of job {}", job.id); let job_dir = create_job_dir(&worker_dir, job.id).await; #[cfg(feature = "benchmark")] let mut bench = windmill_common::bench::BenchmarkIter::new(); @@ -1901,7 +1902,7 @@ pub async fn run_worker( last_executed_job = None; jobs_executed += 1; - tracing::debug!(worker = %worker_name, hostname = %hostname, "started handling of job {}", job.id); + tracing::debug!(target: VERBOSE_TARGET, worker = %worker_name, hostname = %hostname, "started handling of job {}", job.id); if matches!( job.kind, @@ -2835,6 +2836,10 @@ pub async fn handle_queued_job( logs.push_str("Logs are 10x less frequent for this worker\n"); } + if *QUIET_MODE { + logs.push_str("Quiet mode enabled: verbose service logs are suppressed\n"); + } + #[cfg(not(feature = "enterprise"))] if let Connection::Sql(db) = conn { if (job.concurrent_limit.is_some() ||