From a3f86ad34db174b9e0da9529fed1cca8c1dda85b Mon Sep 17 00:00:00 2001 From: Kyle Simpson Date: Mon, 22 Mar 2021 19:00:19 +0000 Subject: [PATCH] Driver: Reduce logging level in general (#48) This change reduces many log levels to debug, particularly where errors are likely to be triggered by undocumented Discord messages or by threads exiting in an unpredictable way. This also reduces the task entry/exit messages to `trace`. This PR has been tested via `cargo make ready`, and by manually inspecting logs at `debug` and `info` levels running `examples/serenity/voice`. --- src/driver/tasks/events.rs | 2 +- src/driver/tasks/message/mod.rs | 6 +++--- src/driver/tasks/mixer.rs | 6 ++---- src/driver/tasks/mod.rs | 16 ++++++++-------- src/driver/tasks/udp_rx.rs | 10 +++++----- src/driver/tasks/udp_tx.rs | 10 +++++----- src/driver/tasks/ws.rs | 10 +++++----- src/ws.rs | 9 ++------- 8 files changed, 31 insertions(+), 38 deletions(-) diff --git a/src/driver/tasks/events.rs b/src/driver/tasks/events.rs index 73b2edb..072f2fb 100644 --- a/src/driver/tasks/events.rs +++ b/src/driver/tasks/events.rs @@ -117,5 +117,5 @@ pub(crate) async fn runner(_interconnect: Interconnect, evt_rx: Receiver { let (events, conn, should_exit) = self.handle_message(m); @@ -138,7 +136,7 @@ impl Mixer { events_failure |= e.should_trigger_interconnect_rebuild(); conn_failure |= e.should_trigger_connect(); - error!("Mixer thread cycle: {:?}", e); + debug!("Mixer thread cycle: {:?}", e); } } else { match self.mix_rx.recv() { diff --git a/src/driver/tasks/mod.rs b/src/driver/tasks/mod.rs index 183ff6a..aacbd7f 100644 --- a/src/driver/tasks/mod.rs +++ b/src/driver/tasks/mod.rs @@ -20,13 +20,13 @@ use message::*; use tokio::{runtime::Handle, spawn}; #[cfg(feature = "tokio-02-marker")] use tokio_compat::{runtime::Handle, spawn}; -use tracing::{error, info, instrument}; +use tracing::{error, instrument, trace}; pub(crate) fn start(config: Config, rx: Receiver, tx: Sender) { spawn(async move { - info!("Driver started."); + trace!("Driver started."); runner(config, rx, tx).await; - info!("Driver finished."); + trace!("Driver finished."); }); } @@ -42,17 +42,17 @@ fn start_internals(core: Sender, config: Config) -> Interconnect { let ic = interconnect.clone(); spawn(async move { - info!("Event processor started."); + trace!("Event processor started."); events::runner(ic, evt_rx).await; - info!("Event processor finished."); + trace!("Event processor finished."); }); let ic = interconnect.clone(); let handle = Handle::current(); std::thread::spawn(move || { - info!("Mixer started."); + trace!("Mixer started."); mixer::runner(ic, mix_rx, handle, config); - info!("Mixer finished."); + trace!("Mixer finished."); }); interconnect @@ -204,6 +204,6 @@ async fn runner(mut config: Config, rx: Receiver, tx: Sender, ) { - info!("UDP receive handle started."); + trace!("UDP receive handle started."); let mut state = UdpRx { cipher, @@ -414,7 +414,7 @@ pub(crate) async fn runner( state.run(&mut interconnect).await; - info!("UDP receive handle stopped."); + trace!("UDP receive handle stopped."); } #[cfg(feature = "tokio-02-marker")] @@ -426,7 +426,7 @@ pub(crate) async fn runner( config: Config, udp_socket: RecvHalf, ) { - info!("UDP receive handle started."); + trace!("UDP receive handle started."); let mut state = UdpRx { cipher, @@ -439,7 +439,7 @@ pub(crate) async fn runner( state.run(&mut interconnect).await; - info!("UDP receive handle stopped."); + trace!("UDP receive handle stopped."); } #[inline] diff --git a/src/driver/tasks/udp_tx.rs b/src/driver/tasks/udp_tx.rs index f6343a9..99e63d0 100644 --- a/src/driver/tasks/udp_tx.rs +++ b/src/driver/tasks/udp_tx.rs @@ -13,7 +13,7 @@ use tokio_compat::{ net::udp::SendHalf, time::{timeout_at, Instant}, }; -use tracing::{error, info, instrument, trace}; +use tracing::{error, instrument, trace}; struct UdpTx { ssrc: u32, @@ -65,7 +65,7 @@ impl UdpTx { #[cfg(not(feature = "tokio-02-marker"))] #[instrument(skip(udp_msg_rx))] pub(crate) async fn runner(udp_msg_rx: Receiver, ssrc: u32, udp_tx: Arc) { - info!("UDP transmit handle started."); + trace!("UDP transmit handle started."); let mut txer = UdpTx { ssrc, @@ -75,13 +75,13 @@ pub(crate) async fn runner(udp_msg_rx: Receiver, ssrc: u32, udp_tx txer.run().await; - info!("UDP transmit handle stopped."); + trace!("UDP transmit handle stopped."); } #[cfg(feature = "tokio-02-marker")] #[instrument(skip(udp_msg_rx))] pub(crate) async fn runner(udp_msg_rx: Receiver, ssrc: u32, udp_tx: SendHalf) { - info!("UDP transmit handle started."); + trace!("UDP transmit handle started."); let mut txer = UdpTx { ssrc, @@ -91,5 +91,5 @@ pub(crate) async fn runner(udp_msg_rx: Receiver, ssrc: u32, udp_tx txer.run().await; - info!("UDP transmit handle stopped."); + trace!("UDP transmit handle stopped."); } diff --git a/src/driver/tasks/ws.rs b/src/driver/tasks/ws.rs index 0eb26d9..e9f3f0d 100644 --- a/src/driver/tasks/ws.rs +++ b/src/driver/tasks/ws.rs @@ -27,7 +27,7 @@ use tokio_compat::{ select, time::{delay_until as sleep_until, Instant}, }; -use tracing::{error, info, instrument, trace, warn}; +use tracing::{debug, info, instrument, trace, warn}; struct AuxNetwork { rx: Receiver, @@ -85,7 +85,7 @@ impl AuxNetwork { ws_msg = self.ws_client.recv_json_no_timeout(), if !self.dont_send => { ws_error = match ws_msg { Err(WsError::Json(e)) => { - warn!("Unexpected JSON {:?}.", e); + debug!("Unexpected JSON {:?}.", e); false }, Err(e) => { @@ -218,11 +218,11 @@ pub(crate) async fn runner( ssrc: u32, heartbeat_interval: f64, ) { - info!("WS thread started."); + trace!("WS thread started."); let mut aux = AuxNetwork::new(evt_rx, ws_client, ssrc, heartbeat_interval); aux.run(&mut interconnect).await; - info!("WS thread finished."); + trace!("WS thread finished."); } fn ws_error_is_not_final(err: WsError) -> bool { @@ -237,7 +237,7 @@ fn ws_error_is_not_final(err: WsError) -> bool { _ => true, }, e => { - error!("Error sending/receiving ws {:?}.", e); + debug!("Error sending/receiving ws {:?}.", e); true }, } diff --git a/src/ws.rs b/src/ws.rs index 30bafcb..0d660fc 100644 --- a/src/ws.rs +++ b/src/ws.rs @@ -26,7 +26,7 @@ use serde_json::Error as JsonError; use tokio::time::{timeout, Duration}; #[cfg(feature = "tokio-02-marker")] use tokio_compat::time::{timeout, Duration}; -use tracing::{instrument, warn}; +use tracing::instrument; pub type WsStream = WebSocketStream; @@ -130,12 +130,7 @@ impl SenderExt for WsStream { #[inline] pub(crate) fn convert_ws_message(message: Option) -> Result> { Ok(match message { - Some(Message::Text(payload)) => - serde_json::from_str(&payload).map(Some).map_err(|why| { - warn!("Err deserializing text: {:?}; text: {}", why, payload,); - - why - })?, + Some(Message::Text(payload)) => serde_json::from_str(&payload).map(Some)?, Some(Message::Binary(bytes)) => { return Err(Error::UnexpectedBinaryMessage(bytes)); },