From f41d8a54e69e256d4b3362996a65392a8453c114 Mon Sep 17 00:00:00 2001 From: MasterPtato Date: Mon, 3 Nov 2025 15:27:37 -0800 Subject: [PATCH] chore: change log levels --- .../api-public/src/runner_configs/upsert.rs | 2 +- engine/packages/cache-purge/src/lib.rs | 6 +--- engine/packages/engine/src/main.rs | 2 +- engine/packages/epoxy/src/http_client.rs | 8 ++--- .../epoxy/src/ops/explicit_prepare.rs | 4 +-- .../packages/epoxy/src/replica/decide_path.rs | 4 +-- .../epoxy/src/replica/lead_consensus.rs | 2 +- .../epoxy/src/replica/message_request.rs | 6 ++-- .../epoxy/src/replica/messages/accept.rs | 2 +- .../epoxy/src/replica/messages/accepted.rs | 2 +- .../epoxy/src/replica/messages/commit.rs | 2 +- .../epoxy/src/replica/messages/committed.rs | 2 +- .../replica/messages/download_instances.rs | 2 +- .../epoxy/src/replica/messages/pre_accept.rs | 2 +- .../epoxy/src/replica/messages/prepare.rs | 2 +- .../src/workflows/coordinator/reconfigure.rs | 22 ++++++------ .../coordinator/replica_status_change.rs | 22 ++++++------ .../epoxy/src/workflows/replica/setup.rs | 20 +++++------ engine/packages/gasoline/src/ctx/message.rs | 2 +- engine/packages/gasoline/src/ctx/workflow.rs | 2 +- engine/packages/gasoline/src/worker.rs | 5 ++- engine/packages/guard/src/lib.rs | 2 +- engine/packages/guard/src/routing/runner.rs | 2 +- engine/packages/metrics/src/providers.rs | 2 +- .../packages/pegboard/src/workflows/runner.rs | 5 ++- engine/packages/runtime/src/traces.rs | 2 +- engine/packages/service-manager/src/lib.rs | 36 +++++++++---------- .../packages/tracing-reconfigure/src/lib.rs | 8 ++--- .../src/driver/postgres/mod.rs | 4 +-- engine/packages/universalpubsub/src/pubsub.rs | 4 +-- 30 files changed, 92 insertions(+), 94 deletions(-) diff --git a/engine/packages/api-public/src/runner_configs/upsert.rs b/engine/packages/api-public/src/runner_configs/upsert.rs index b13d311ca4..ac532d3b18 100644 --- a/engine/packages/api-public/src/runner_configs/upsert.rs +++ b/engine/packages/api-public/src/runner_configs/upsert.rs @@ -171,7 +171,7 @@ async fn upsert_inner( ) .await { - tracing::warn!(?err, runner_name = ?path.runner_name, "failed to refresh runner config metadata"); + tracing::warn!(?err, runner_name=?path.runner_name, "failed to refresh runner config metadata"); } } else { tracing::debug!("endpoint config unchanged, skipping metadata refresh"); diff --git a/engine/packages/cache-purge/src/lib.rs b/engine/packages/cache-purge/src/lib.rs index 357b779986..a08b0a9c78 100644 --- a/engine/packages/cache-purge/src/lib.rs +++ b/engine/packages/cache-purge/src/lib.rs @@ -5,13 +5,11 @@ use universalpubsub::NextOutput; #[tracing::instrument(skip_all)] pub async fn start(config: rivet_config::Config, pools: rivet_pools::Pools) -> Result<()> { - tracing::info!("starting cache purge subscriber service"); - // Subscribe to cache purge updates let ups = pools.ups()?; let mut sub = ups.subscribe(CACHE_PURGE_TOPIC).await?; - tracing::info!(subject = ?CACHE_PURGE_TOPIC, "subscribed to cache purge updates"); + tracing::info!(subject=?CACHE_PURGE_TOPIC, "subscribed to cache purge updates"); // Get cache instance let cache = rivet_cache::CacheInner::from_env(&config, pools)?; @@ -42,7 +40,5 @@ pub async fn start(config: rivet_config::Config, pools: rivet_pools::Pools) -> R } } - tracing::warn!("cache purge subscriber service stopped"); - Ok(()) } diff --git a/engine/packages/engine/src/main.rs b/engine/packages/engine/src/main.rs index f1129d2f13..b352e28ce4 100644 --- a/engine/packages/engine/src/main.rs +++ b/engine/packages/engine/src/main.rs @@ -25,7 +25,7 @@ async fn main_inner() -> Result<()> { // Load config let config = rivet_config::Config::load(&cli.config).await?; - tracing::info!(config = ?*config, "loaded config"); + tracing::info!(config=?*config, "loaded config"); // Initialize telemetry (does nothing if telemetry is disabled) let _guard = rivet_telemetry::init(&config); diff --git a/engine/packages/epoxy/src/http_client.rs b/engine/packages/epoxy/src/http_client.rs index 895fbc3716..2b5a859783 100644 --- a/engine/packages/epoxy/src/http_client.rs +++ b/engine/packages/epoxy/src/http_client.rs @@ -57,7 +57,7 @@ where ) .collect::>() .await; - tracing::info!(?quorum_size, len = ?responses.len(), ?quorum_type, "fanout quorum size"); + tracing::debug!(?quorum_size, len = ?responses.len(), ?quorum_type, "fanout quorum size"); // Choose how many successful responses we need before considering a success let target_responses = match quorum_type { @@ -115,7 +115,7 @@ pub async fn send_message_to_address( let to_replica_id = request.to_replica_id; if from_replica_id == to_replica_id { - tracing::info!( + tracing::debug!( to_replica = to_replica_id, "sending message to replica directly" ); @@ -126,7 +126,7 @@ pub async fn send_message_to_address( let mut replica_url = url::Url::parse(&replica_url)?; replica_url.set_path(&format!("/v{PROTOCOL_VERSION}/epoxy/message")); - tracing::info!( + tracing::debug!( to_replica = to_replica_id, %replica_url, "sending message to replica via http" @@ -183,7 +183,7 @@ pub async fn send_message_to_address( let body = response.bytes().await?; let response_body = versioned::Response::deserialize(&body)?; - tracing::info!( + tracing::debug!( to_replica = to_replica_id, "successfully sent message via http" ); diff --git a/engine/packages/epoxy/src/ops/explicit_prepare.rs b/engine/packages/epoxy/src/ops/explicit_prepare.rs index 2445f9d034..28a8c15797 100644 --- a/engine/packages/epoxy/src/ops/explicit_prepare.rs +++ b/engine/packages/epoxy/src/ops/explicit_prepare.rs @@ -28,7 +28,7 @@ pub async fn epoxy_explicit_prepare( let replica_id = ctx.config().epoxy_replica_id(); let instance = &input.instance; - tracing::info!( + tracing::debug!( ?instance, "starting explicit prepare for potentially failed replica" ); @@ -317,7 +317,7 @@ async fn restart_phase1( commands: commands.unwrap_or_else(|| vec![]), // Empty vec for no-op }; - tracing::info!( + tracing::debug!( ?instance, commands_count = proposal.commands.len(), "restarting phase1 with propose operation" diff --git a/engine/packages/epoxy/src/replica/decide_path.rs b/engine/packages/epoxy/src/replica/decide_path.rs index 1b7022728f..2c9112f7c8 100644 --- a/engine/packages/epoxy/src/replica/decide_path.rs +++ b/engine/packages/epoxy/src/replica/decide_path.rs @@ -9,7 +9,7 @@ pub fn decide_path( pre_accept_oks: Vec, payload: &protocol::Payload, ) -> Result { - tracing::info!(instance=?payload.instance, "deciding path"); + tracing::debug!(instance=?payload.instance, "deciding path"); let mut new_payload = payload.clone(); let mut path = protocol::Path::PathFast(protocol::PathFast { @@ -29,7 +29,7 @@ pub fn decide_path( // EPaxos Steps 11 (returns PathFast) continue; } else { - tracing::info!(?pre_accept_ok.deps, "received dissenting voice"); + tracing::debug!(?pre_accept_ok.deps, "received dissenting voice"); // EPaxos Step 13 let new_deps = utils::union_deps(new_payload.deps, pre_accept_ok.deps); diff --git a/engine/packages/epoxy/src/replica/lead_consensus.rs b/engine/packages/epoxy/src/replica/lead_consensus.rs index 5af4edda10..7235650e43 100644 --- a/engine/packages/epoxy/src/replica/lead_consensus.rs +++ b/engine/packages/epoxy/src/replica/lead_consensus.rs @@ -12,7 +12,7 @@ pub async fn lead_consensus( replica_id: protocol::ReplicaId, proposal: protocol::Proposal, ) -> Result { - tracing::info!(?replica_id, "leading consensus"); + tracing::debug!(?replica_id, "leading consensus"); // EPaxos Step 1 let instance_num_key = keys::replica::InstanceNumberKey; diff --git a/engine/packages/epoxy/src/replica/message_request.rs b/engine/packages/epoxy/src/replica/message_request.rs index 7466c3331c..3d96e5c2bb 100644 --- a/engine/packages/epoxy/src/replica/message_request.rs +++ b/engine/packages/epoxy/src/replica/message_request.rs @@ -14,7 +14,7 @@ pub async fn message_request( let kind = match request.kind { protocol::RequestKind::UpdateConfigRequest(req) => { - tracing::info!( + tracing::debug!( epoch = ?req.config.epoch, replica_count = req.config.replicas.len(), "received configuration update request" @@ -103,7 +103,7 @@ pub async fn message_request( } protocol::RequestKind::CoordinatorUpdateReplicaStatusRequest(req) => { // Send signal to coordinator workflow - tracing::info!( + tracing::debug!( ?current_replica_id, update_replica_id=?req.replica_id, update_status=?req.status, @@ -124,7 +124,7 @@ pub async fn message_request( } protocol::RequestKind::BeginLearningRequest(req) => { // Send signal to replica workflow - tracing::info!(?current_replica_id, "received begin learning request"); + tracing::debug!(?current_replica_id, "received begin learning request"); ctx.signal(crate::workflows::replica::BeginLearning { config: req.config.clone().into(), diff --git a/engine/packages/epoxy/src/replica/messages/accept.rs b/engine/packages/epoxy/src/replica/messages/accept.rs index 35744520cc..90c15d48f9 100644 --- a/engine/packages/epoxy/src/replica/messages/accept.rs +++ b/engine/packages/epoxy/src/replica/messages/accept.rs @@ -17,7 +17,7 @@ pub async fn accept( instance, } = accept_req.payload; - tracing::info!(?replica_id, ?instance, "handling accept message"); + tracing::debug!(?replica_id, ?instance, "handling accept message"); // Validate ballot let current_ballot = ballot::get_ballot(tx, replica_id).await?; diff --git a/engine/packages/epoxy/src/replica/messages/accepted.rs b/engine/packages/epoxy/src/replica/messages/accepted.rs index b91d5e24e4..63ea67f678 100644 --- a/engine/packages/epoxy/src/replica/messages/accepted.rs +++ b/engine/packages/epoxy/src/replica/messages/accepted.rs @@ -18,7 +18,7 @@ pub async fn accepted( instance, } = payload; - tracing::info!(?replica_id, ?instance, "handling accepted message"); + tracing::debug!(?replica_id, ?instance, "handling accepted message"); // Create accepted log entry let current_ballot = ballot::get_ballot(tx, replica_id).await?; diff --git a/engine/packages/epoxy/src/replica/messages/commit.rs b/engine/packages/epoxy/src/replica/messages/commit.rs index e85aff3d1a..01ca1408e7 100644 --- a/engine/packages/epoxy/src/replica/messages/commit.rs +++ b/engine/packages/epoxy/src/replica/messages/commit.rs @@ -19,7 +19,7 @@ pub async fn commit( instance, } = commit_req.payload; - tracing::info!(?replica_id, ?instance, "handling commit message"); + tracing::debug!(?replica_id, ?instance, "handling commit message"); // EPaxos Step 24 let current_ballot = ballot::get_ballot(tx, replica_id).await?; diff --git a/engine/packages/epoxy/src/replica/messages/committed.rs b/engine/packages/epoxy/src/replica/messages/committed.rs index 3ad726157d..9e95ee5626 100644 --- a/engine/packages/epoxy/src/replica/messages/committed.rs +++ b/engine/packages/epoxy/src/replica/messages/committed.rs @@ -18,7 +18,7 @@ pub async fn committed( instance, } = payload; - tracing::info!(?replica_id, ?instance, "handling committed message"); + tracing::debug!(?replica_id, ?instance, "handling committed message"); // EPaxos Step 21: Create committed log entry let current_ballot = ballot::get_ballot(tx, replica_id).await?; diff --git a/engine/packages/epoxy/src/replica/messages/download_instances.rs b/engine/packages/epoxy/src/replica/messages/download_instances.rs index 2f7c9b37e7..7942a61252 100644 --- a/engine/packages/epoxy/src/replica/messages/download_instances.rs +++ b/engine/packages/epoxy/src/replica/messages/download_instances.rs @@ -12,7 +12,7 @@ pub async fn download_instances( replica_id: ReplicaId, req: protocol::DownloadInstancesRequest, ) -> Result> { - tracing::info!(?replica_id, "handling download instances message"); + tracing::debug!(?replica_id, "handling download instances message"); let mut entries = Vec::new(); let subspace = keys::subspace(replica_id); diff --git a/engine/packages/epoxy/src/replica/messages/pre_accept.rs b/engine/packages/epoxy/src/replica/messages/pre_accept.rs index ecbcde3327..69091386b1 100644 --- a/engine/packages/epoxy/src/replica/messages/pre_accept.rs +++ b/engine/packages/epoxy/src/replica/messages/pre_accept.rs @@ -11,7 +11,7 @@ pub async fn pre_accept( replica_id: protocol::ReplicaId, pre_accept_req: protocol::PreAcceptRequest, ) -> Result { - tracing::info!(?replica_id, "handling pre-accept message"); + tracing::debug!(?replica_id, "handling pre-accept message"); let protocol::Payload { proposal, diff --git a/engine/packages/epoxy/src/replica/messages/prepare.rs b/engine/packages/epoxy/src/replica/messages/prepare.rs index 19d50cb816..a3f76d7f73 100644 --- a/engine/packages/epoxy/src/replica/messages/prepare.rs +++ b/engine/packages/epoxy/src/replica/messages/prepare.rs @@ -11,7 +11,7 @@ pub async fn prepare( replica_id: protocol::ReplicaId, prepare_req: protocol::PrepareRequest, ) -> Result { - tracing::info!(?replica_id, "handling prepare message"); + tracing::debug!(?replica_id, "handling prepare message"); let protocol::PrepareRequest { ballot, instance } = prepare_req; diff --git a/engine/packages/epoxy/src/workflows/coordinator/reconfigure.rs b/engine/packages/epoxy/src/workflows/coordinator/reconfigure.rs index fbc5ccca51..e0ab58cae8 100644 --- a/engine/packages/epoxy/src/workflows/coordinator/reconfigure.rs +++ b/engine/packages/epoxy/src/workflows/coordinator/reconfigure.rs @@ -63,7 +63,7 @@ pub async fn check_config_changes( ctx: &ActivityCtx, _input: &CheckConfigChangesInput, ) -> Result> { - tracing::info!("checking for config changes"); + tracing::debug!("checking for config changes"); let state = ctx.state::()?; @@ -107,7 +107,7 @@ pub async fn check_config_changes( .collect(); if new_replicas.is_empty() { - tracing::info!("no new replicas found"); + tracing::debug!("no new replicas found"); return Ok(None); } @@ -144,7 +144,7 @@ pub async fn health_check_new_replicas( return Ok(false); } - tracing::info!( + tracing::debug!( new_replicas = ?input.new_replicas, "health checking new replicas" ); @@ -154,7 +154,7 @@ pub async fn health_check_new_replicas( let replica_id = replica.replica_id; async move { - tracing::info!(?replica_id, "sending health check to replica"); + tracing::debug!(?replica_id, "sending health check to replica"); let from_replica_id = ctx.config().epoxy_replica_id(); let request = protocol::Request { @@ -171,7 +171,7 @@ pub async fn health_check_new_replicas( .await .with_context(|| format!("health check failed for replica {}", replica_id))?; - tracing::info!(?replica_id, "health check successful"); + tracing::debug!(?replica_id, "health check successful"); Ok(()) } }); @@ -199,7 +199,7 @@ pub async fn add_replicas_as_joining( state.config.replicas.push(replica.clone().into()); } - tracing::info!("added {} replicas as joining", input.new_replicas.len()); + tracing::debug!("added {} replicas as joining", input.new_replicas.len()); // IMPORTANT: Do not increment epoch at this stage, despite what the EPaxos paper recommends. // See epoxy/README.md for more details. @@ -231,7 +231,7 @@ pub async fn send_begin_learning( let config = config.clone(); async move { - tracing::info!(?replica_id, "sending begin learning to replica"); + tracing::debug!(?replica_id, "sending begin learning to replica"); let request = protocol::Request { from_replica_id: ctx.config().epoxy_replica_id(), @@ -244,7 +244,7 @@ pub async fn send_begin_learning( crate::http_client::send_message(&ApiCtx::new_from_activity(&ctx)?, &config, request) .await?; - tracing::info!(?replica_id, "begin learning sent successfully"); + tracing::debug!(?replica_id, "begin learning sent successfully"); Ok(()) } }); @@ -266,21 +266,21 @@ fn should_abort_reconfigure( .iter() .find(|x| x.datacenter_label as u64 == replica.replica_id) else { - tracing::info!( + tracing::debug!( "config changed during reconfigure (replica removed), aborting reconfigure" ); return Ok(true); }; if url::Url::parse(&replica.api_peer_url)? != current_dc.peer_url { - tracing::info!( + tracing::debug!( "config changed during reconfigure (api_peer_url changed), aborting reconfigure" ); return Ok(true); } if url::Url::parse(&replica.guard_url)? != current_dc.public_url { - tracing::info!( + tracing::debug!( "config changed during reconfigure (guard_url changed), aborting reconfigure" ); return Ok(true); diff --git a/engine/packages/epoxy/src/workflows/coordinator/replica_status_change.rs b/engine/packages/epoxy/src/workflows/coordinator/replica_status_change.rs index 7445616136..44a3abbe61 100644 --- a/engine/packages/epoxy/src/workflows/coordinator/replica_status_change.rs +++ b/engine/packages/epoxy/src/workflows/coordinator/replica_status_change.rs @@ -85,9 +85,9 @@ pub async fn update_replica_status( // Update status replica_state.status = input.new_status.clone().into(); - tracing::info!( - replica_id = ?input.replica_id, - new_status = ?input.new_status, + tracing::debug!( + replica_id=?input.replica_id, + new_status=?input.new_status, "updated replica status" ); @@ -103,7 +103,7 @@ pub async fn increment_epoch(ctx: &ActivityCtx, _input: &IncrementEpochInput) -> state.config.epoch += 1; - tracing::info!(new_epoch = state.config.epoch, "incremented epoch"); + tracing::debug!(new_epoch = state.config.epoch, "incremented epoch"); Ok(()) } @@ -119,7 +119,7 @@ pub async fn update_replica_urls(ctx: &ActivityCtx, _input: &UpdateReplicaUrlsIn for replica in state.config.replicas.iter_mut() { let Some(dc) = ctx.config().dc_for_label(replica.replica_id as u16) else { tracing::warn!( - replica_id = ?replica.replica_id, + replica_id=?replica.replica_id, "datacenter not found for replica, skipping url update" ); continue; @@ -128,10 +128,10 @@ pub async fn update_replica_urls(ctx: &ActivityCtx, _input: &UpdateReplicaUrlsIn replica.api_peer_url = dc.peer_url.to_string(); replica.guard_url = dc.public_url.to_string(); - tracing::info!( - replica_id = ?replica.replica_id, - api_peer_url = ?dc.peer_url, - guard_url = ?dc.public_url, + tracing::debug!( + replica_id=?replica.replica_id, + api_peer_url=?dc.peer_url, + guard_url=?dc.public_url, "updated replica urls" ); } @@ -156,7 +156,7 @@ pub async fn notify_all_replicas( let config: protocol::ClusterConfig = state.config.clone().into(); - tracing::info!( + tracing::debug!( epoch = config.epoch, replica_count = config.replicas.len(), "notifying all replicas of config change" @@ -180,7 +180,7 @@ pub async fn notify_all_replicas( .await .with_context(|| format!("failed to update config for replica {}", replica_id))?; - tracing::info!(?replica_id, "config update sent"); + tracing::debug!(?replica_id, "config update sent"); Ok(()) } }); diff --git a/engine/packages/epoxy/src/workflows/replica/setup.rs b/engine/packages/epoxy/src/workflows/replica/setup.rs index 5f7783032b..c85993e6d5 100644 --- a/engine/packages/epoxy/src/workflows/replica/setup.rs +++ b/engine/packages/epoxy/src/workflows/replica/setup.rs @@ -117,7 +117,7 @@ pub async fn setup_replica(ctx: &mut WorkflowCtx, _input: &super::Input) -> Resu state.total_recovered_keys += output.recovered_count; } else { // No more keys to recover - tracing::info!( + tracing::debug!( total_recovered_keys = state.total_recovered_keys, "finished recovering keys" ); @@ -172,7 +172,7 @@ pub async fn download_instances_chunk( let config = &input.learning_config; let proto_config: protocol::ClusterConfig = input.learning_config.clone().into(); - tracing::info!( + tracing::debug!( from_replica_id = ?input.from_replica_id, replica_progress = format!("{}/{}", input.replica_index, input.total_replicas - 1), // -1 to exclude self total_downloaded_instances = input.total_downloaded_instances, @@ -201,7 +201,7 @@ pub async fn download_instances_chunk( }; let instances = download_response.instances; - tracing::info!(instance_count = instances.len(), "received instances"); + tracing::debug!(instance_count = instances.len(), "received instances"); // Apply each log entry from the downloaded instances let total_entries = instances.len(); @@ -230,7 +230,7 @@ pub async fn download_instances_chunk( applied_count += 1; } - tracing::info!( + tracing::debug!( total_entries, applied_count, skipped_count, @@ -269,7 +269,7 @@ async fn apply_log_entry( ) -> Result<()> { let replica_id = ctx.config().epoxy_replica_id(); - tracing::info!( + tracing::debug!( ?instance, ?log_entry.state, "replaying log entry" @@ -334,7 +334,7 @@ async fn apply_log_entry( .custom_instrument(tracing::info_span!("apply_log_entry_tx")) .await?; - tracing::info!( + tracing::debug!( ?instance, ?log_entry.state, "successfully replayed log entry" @@ -392,7 +392,7 @@ pub async fn recover_keys_chunk( ) -> Result { let replica_id = ctx.config().epoxy_replica_id(); - tracing::info!( + tracing::debug!( ?replica_id, total_recovered_keys = input.total_recovered_keys, after_key_len = input.after_key.as_ref().map(|k| k.len()), @@ -534,7 +534,7 @@ pub async fn recover_keys_chunk( None }; - tracing::info!( + tracing::debug!( ?replica_id, recovered_count, scanned_count, @@ -801,7 +801,7 @@ pub async fn notify_active(ctx: &ActivityCtx, input: &NotifyActiveInput) -> Resu let config = &input.learning_config; let proto_config: protocol::ClusterConfig = config.clone().into(); - tracing::info!("notifying coordinator that replica is active"); + tracing::debug!("notifying coordinator that replica is active"); // Send status update to coordinator let request = protocol::Request { @@ -818,6 +818,6 @@ pub async fn notify_active(ctx: &ActivityCtx, input: &NotifyActiveInput) -> Resu crate::http_client::send_message(&ApiCtx::new_from_activity(&ctx)?, &proto_config, request) .await?; - tracing::info!("notified coordinator of active status"); + tracing::debug!("notified coordinator of active status"); Ok(()) } diff --git a/engine/packages/gasoline/src/ctx/message.rs b/engine/packages/gasoline/src/ctx/message.rs index 6af2b3e50e..b4e1d73cdc 100644 --- a/engine/packages/gasoline/src/ctx/message.rs +++ b/engine/packages/gasoline/src/ctx/message.rs @@ -162,7 +162,7 @@ impl MessageCtx { ) .await { - tracing::warn!(?err, "publish message failed, trying again"); + tracing::debug!(?err, "publish message failed, trying again"); continue; } diff --git a/engine/packages/gasoline/src/ctx/workflow.rs b/engine/packages/gasoline/src/ctx/workflow.rs index 25d79ea7d0..8987624f31 100644 --- a/engine/packages/gasoline/src/ctx/workflow.rs +++ b/engine/packages/gasoline/src/ctx/workflow.rs @@ -1051,7 +1051,7 @@ impl WorkflowCtx { // No-op if duration <= 0 { - if !replay && duration < -50 { + if !replay && duration < -25 { tracing::warn!(%duration, "tried to sleep for a negative duration"); } } diff --git a/engine/packages/gasoline/src/worker.rs b/engine/packages/gasoline/src/worker.rs index 471276146d..43b1680040 100644 --- a/engine/packages/gasoline/src/worker.rs +++ b/engine/packages/gasoline/src/worker.rs @@ -152,7 +152,10 @@ impl Worker { for (workflow_id, wf) in &self.running_workflows { if wf.stop.send(()).is_err() { - tracing::warn!(?workflow_id, "stop channel closed"); + tracing::warn!( + ?workflow_id, + "stop channel closed, workflow likely already stopped" + ); } } diff --git a/engine/packages/guard/src/lib.rs b/engine/packages/guard/src/lib.rs index f7533372e3..a09e0fd912 100644 --- a/engine/packages/guard/src/lib.rs +++ b/engine/packages/guard/src/lib.rs @@ -24,7 +24,7 @@ pub async fn start(config: rivet_config::Config, pools: rivet_pools::Pools) -> R // Initialize with a default CryptoProvider for rustls let provider = rustls::crypto::ring::default_provider(); if provider.install_default().is_err() { - tracing::warn!("crypto provider already installed in this process"); + tracing::debug!("crypto provider already installed in this process"); } // Share shared context diff --git a/engine/packages/guard/src/routing/runner.rs b/engine/packages/guard/src/routing/runner.rs index f090d3b49c..e616d86731 100644 --- a/engine/packages/guard/src/routing/runner.rs +++ b/engine/packages/guard/src/routing/runner.rs @@ -54,7 +54,7 @@ async fn route_runner_internal( // Validate that the host is valid for the current datacenter let current_dc = ctx.config().topology().current_dc()?; if !current_dc.is_valid_regional_host(host) { - tracing::warn!(?host, datacenter = ?current_dc.name, "invalid host for current datacenter"); + tracing::warn!(?host, datacenter=?current_dc.name, "invalid host for current datacenter"); // Determine valid hosts for error message let valid_hosts = if let Some(hosts) = ¤t_dc.valid_hosts { diff --git a/engine/packages/metrics/src/providers.rs b/engine/packages/metrics/src/providers.rs index aac9a1b092..72771180ee 100644 --- a/engine/packages/metrics/src/providers.rs +++ b/engine/packages/metrics/src/providers.rs @@ -66,7 +66,7 @@ pub fn set_sampler_ratio(ratio: f64) -> anyhow::Result<()> { .ok_or_else(|| anyhow::anyhow!("sampler not initialized"))?; sampler.set_ratio(ratio); - tracing::info!(?ratio, "updated sampler ratio"); + tracing::debug!(?ratio, "updated sampler ratio"); Ok(()) } diff --git a/engine/packages/pegboard/src/workflows/runner.rs b/engine/packages/pegboard/src/workflows/runner.rs index 33c4840d0c..43c1c876e6 100644 --- a/engine/packages/pegboard/src/workflows/runner.rs +++ b/engine/packages/pegboard/src/workflows/runner.rs @@ -253,7 +253,10 @@ pub async fn pegboard_runner(ctx: &mut WorkflowCtx, input: &Input) -> Result<()> true, ) = (&command.inner, state.draining) { - tracing::warn!(?actor_id, "attempt to schedule actor to draining runner"); + tracing::warn!( + ?actor_id, + "attempt to schedule actor to draining runner, reallocating" + ); let res = ctx .signal(crate::workflows::actor::Lost { diff --git a/engine/packages/runtime/src/traces.rs b/engine/packages/runtime/src/traces.rs index 182baea806..ebe015d4cb 100644 --- a/engine/packages/runtime/src/traces.rs +++ b/engine/packages/runtime/src/traces.rs @@ -152,7 +152,7 @@ pub fn reload_log_filter(filter_spec: &str) -> anyhow::Result<()> { // Reload the filter handle.reload(env_filter)?; - tracing::info!(?filter_spec, "reloaded log filter"); + tracing::debug!(?filter_spec, "reloaded log filter"); Ok(()) } diff --git a/engine/packages/service-manager/src/lib.rs b/engine/packages/service-manager/src/lib.rs index f48fee8900..0aa53e7e30 100644 --- a/engine/packages/service-manager/src/lib.rs +++ b/engine/packages/service-manager/src/lib.rs @@ -122,12 +122,12 @@ pub async fn start( services: Vec, ) -> Result<()> { // Spawn services - tracing::info!(services = ?services.len(), "starting services"); + tracing::info!(services=?services.len(), "starting services"); let mut join_set = tokio::task::JoinSet::new(); let cron_schedule = tokio_cron_scheduler::JobScheduler::new().await?; let mut sleep_indefinitely = false; for service in services { - tracing::debug!(name = %service.name, kind = ?service.kind, "server starting service"); + tracing::debug!(name=%service.name, kind=?service.kind, "server starting service"); match service.kind.behavior() { ServiceBehavior::Service => { @@ -138,21 +138,21 @@ pub async fn start( let config = config.clone(); let pools = pools.clone(); async move { - tracing::debug!(service = %service.name, "starting service"); + tracing::debug!(service=%service.name, "starting service"); loop { match (service.run)(config.clone(), pools.clone()).await { Result::Ok(_) => { - tracing::error!(service = %service.name, "service exited unexpectedly"); + tracing::error!(service=%service.name, "service exited unexpectedly"); } Err(err) => { - tracing::error!(service = %service.name, ?err, "service crashed"); + tracing::error!(service=%service.name, ?err, "service crashed"); } } tokio::time::sleep(Duration::from_secs(1)).await; - tracing::info!(service = %service.name, "restarting service"); + tracing::info!(service=%service.name, "restarting service"); } } }) @@ -166,20 +166,20 @@ pub async fn start( let config = config.clone(); let pools = pools.clone(); async move { - tracing::debug!(oneoff = %service.name, "starting oneoff"); + tracing::debug!(oneoff=%service.name, "starting oneoff"); loop { match (service.run)(config.clone(), pools.clone()).await { Result::Ok(_) => { - tracing::debug!(oneoff = %service.name, "oneoff finished"); + tracing::debug!(oneoff=%service.name, "oneoff finished"); break; } Err(err) => { - tracing::error!(oneoff = %service.name, ?err, "oneoff crashed"); + tracing::error!(oneoff=%service.name, ?err, "oneoff crashed"); tokio::time::sleep(Duration::from_secs(1)).await; - tracing::info!(oneoff = %service.name, "restarting oneoff"); + tracing::info!(oneoff=%service.name, "restarting oneoff"); } } } @@ -200,20 +200,20 @@ pub async fn start( let config = config.clone(); let pools = pools.clone(); async move { - tracing::debug!(cron = %service.name, "starting immediate cron"); + tracing::debug!(cron=%service.name, "starting immediate cron"); for attempt in 1..=8 { match (service.run)(config.clone(), pools.clone()).await { Result::Ok(_) => { - tracing::debug!(cron = %service.name, ?attempt, "cron finished"); + tracing::debug!(cron=%service.name, ?attempt, "cron finished"); break; } Err(err) => { - tracing::error!(cron = %service.name, ?attempt, ?err, "cron crashed"); + tracing::error!(cron=%service.name, ?attempt, ?err, "cron crashed"); tokio::time::sleep(Duration::from_secs(1)).await; - tracing::info!(cron = %service.name, ?attempt, "restarting cron"); + tracing::info!(cron=%service.name, ?attempt, "restarting cron"); } } } @@ -235,20 +235,20 @@ pub async fn start( let pools = pools.clone(); let service = service.clone(); Box::pin(async move { - tracing::debug!(cron = %service.name, ?notification, "running cron"); + tracing::debug!(cron=%service.name, ?notification, "running cron"); for attempt in 1..=8 { match (service.run)(config.clone(), pools.clone()).await { Result::Ok(_) => { - tracing::debug!(cron = %service.name, ?attempt, "cron finished"); + tracing::debug!(cron=%service.name, ?attempt, "cron finished"); return; } Err(err) => { - tracing::error!(cron = %service.name, ?attempt, ?err, "cron crashed"); + tracing::error!(cron=%service.name, ?attempt, ?err, "cron crashed"); tokio::time::sleep(Duration::from_secs(1)).await; - tracing::info!(cron = %service.name, ?attempt, "restarting cron"); + tracing::info!(cron=%service.name, ?attempt, "restarting cron"); } } } diff --git a/engine/packages/tracing-reconfigure/src/lib.rs b/engine/packages/tracing-reconfigure/src/lib.rs index 9151db195b..0d4110fd9a 100644 --- a/engine/packages/tracing-reconfigure/src/lib.rs +++ b/engine/packages/tracing-reconfigure/src/lib.rs @@ -13,20 +13,18 @@ pub struct SetTracingConfigMessage { #[tracing::instrument(skip_all)] pub async fn start(_config: rivet_config::Config, pools: rivet_pools::Pools) -> Result<()> { - tracing::info!("starting tracing reconfigure subscriber service"); - // Subscribe to tracing config updates let ups = pools.ups()?; let subject = "rivet.debug.tracing.config"; let mut sub = ups.subscribe(subject).await?; - tracing::info!(subject = ?subject, "subscribed to tracing config updates"); + tracing::debug!(subject = ?subject, "subscribed to tracing config updates"); // Process incoming messages while let Ok(NextOutput::Message(msg)) = sub.next().await { match serde_json::from_slice::(&msg.payload) { Ok(update_msg) => { - tracing::info!( + tracing::debug!( filter = ?update_msg.filter, sampler_ratio = ?update_msg.sampler_ratio, "received tracing config update" @@ -76,7 +74,5 @@ pub async fn start(_config: rivet_config::Config, pools: rivet_pools::Pools) -> } } - tracing::warn!("tracing reconfigure subscriber service stopped"); - Ok(()) } diff --git a/engine/packages/universalpubsub/src/driver/postgres/mod.rs b/engine/packages/universalpubsub/src/driver/postgres/mod.rs index ca801e81b2..f60ba6f6f8 100644 --- a/engine/packages/universalpubsub/src/driver/postgres/mod.rs +++ b/engine/packages/universalpubsub/src/driver/postgres/mod.rs @@ -116,7 +116,7 @@ impl PostgresDriver { loop { match tokio_postgres::connect(&conn_str, tokio_postgres::NoTls).await { Result::Ok((new_client, conn)) => { - tracing::info!("postgres listen connection established"); + tracing::debug!("postgres listen connection established"); // Reset backoff on successful connection backoff = Backoff::default(); @@ -148,7 +148,7 @@ impl PostgresDriver { "re-subscribing to channels after reconnection" ); for channel in &channels { - tracing::info!(?channel, "re-subscribing to channel"); + tracing::debug!(?channel, "re-subscribing to channel"); if let Result::Err(e) = new_client .execute(&format!("LISTEN \"{}\"", channel), &[]) .await diff --git a/engine/packages/universalpubsub/src/pubsub.rs b/engine/packages/universalpubsub/src/pubsub.rs index ac6ff27696..a0a22d9fae 100644 --- a/engine/packages/universalpubsub/src/pubsub.rs +++ b/engine/packages/universalpubsub/src/pubsub.rs @@ -190,11 +190,11 @@ impl PubSub { match self.driver.publish(subject, encoded).await { Result::Ok(_) => break, Err(err) if !backoff.tick().await => { - tracing::info!(?err, "error publishing, cannot retry again"); + tracing::warn!(?err, "error publishing, cannot retry again"); return Err(crate::errors::Ups::PublishFailed.build().into()); } Err(err) => { - tracing::info!(?err, "error publishing, retrying"); + tracing::debug!(?err, "error publishing, retrying"); // Continue retrying } }