servius/songbird
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Driver: Reduce logging level in general (#48)

Browse Source 
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`.
This commit is contained in:
Kyle Simpson
2021-03-22 19:00:19 +00:00
committed by GitHub
parent 1fcc8c0eb9
commit a3f86ad34d
8 changed files with 31 additions and 38 deletions
Download Patch File Download Diff File Expand all files Collapse all files

2
src/driver/tasks/events.rs
View File

@@ -117,5 +117,5 @@ pub(crate) async fn runner(_interconnect: Interconnect, evt_rx: Receiver<EventMe
} }
} }
info!("Event thread exited."); trace!("Event thread exited.");
} }

6
src/driver/tasks/message/mod.rs
View File

@@ -15,7 +15,7 @@ use flume::Sender;
use tokio::spawn; use tokio::spawn;
#[cfg(feature = "tokio-02-marker")] #[cfg(feature = "tokio-02-marker")]
use tokio_compat::spawn; use tokio_compat::spawn;
use tracing::info; use tracing::trace;
#[derive(Clone, Debug)] #[derive(Clone, Debug)]
pub struct Interconnect { pub struct Interconnect {
@@ -43,9 +43,9 @@ impl Interconnect {
let ic = self.clone(); let ic = self.clone();
spawn(async move { spawn(async move {
info!("Event processor restarted."); trace!("Event processor restarted.");
super::events::runner(ic, evt_rx).await; super::events::runner(ic, evt_rx).await;
info!("Event processor finished."); trace!("Event processor finished.");
}); });
// Make mixer aware of new targets... // Make mixer aware of new targets...

6
src/driver/tasks/mixer.rs
View File

@@ -22,7 +22,7 @@ use std::time::Instant;
use tokio::runtime::Handle; use tokio::runtime::Handle;
#[cfg(feature = "tokio-02-marker")] #[cfg(feature = "tokio-02-marker")]
use tokio_compat::runtime::Handle; use tokio_compat::runtime::Handle;
use tracing::{error, instrument}; use tracing::{debug, error, instrument};
use xsalsa20poly1305::TAG_SIZE; use xsalsa20poly1305::TAG_SIZE;
pub struct Mixer { pub struct Mixer {
@@ -111,8 +111,6 @@ impl Mixer {
'runner: loop { 'runner: loop {
if self.conn_active.is_some() { if self.conn_active.is_some() {
loop { loop {
use MixerMessage::*;
match self.mix_rx.try_recv() { match self.mix_rx.try_recv() {
Ok(m) => { Ok(m) => {
let (events, conn, should_exit) = self.handle_message(m); let (events, conn, should_exit) = self.handle_message(m);
@@ -138,7 +136,7 @@ impl Mixer {
events_failure |= e.should_trigger_interconnect_rebuild(); events_failure |= e.should_trigger_interconnect_rebuild();
conn_failure |= e.should_trigger_connect(); conn_failure |= e.should_trigger_connect();
error!("Mixer thread cycle: {:?}", e); debug!("Mixer thread cycle: {:?}", e);
} }
} else { } else {
match self.mix_rx.recv() { match self.mix_rx.recv() {

16
src/driver/tasks/mod.rs
View File

@@ -20,13 +20,13 @@ use message::*;
use tokio::{runtime::Handle, spawn}; use tokio::{runtime::Handle, spawn};
#[cfg(feature = "tokio-02-marker")] #[cfg(feature = "tokio-02-marker")]
use tokio_compat::{runtime::Handle, spawn}; use tokio_compat::{runtime::Handle, spawn};
use tracing::{error, info, instrument}; use tracing::{error, instrument, trace};
pub(crate) fn start(config: Config, rx: Receiver<CoreMessage>, tx: Sender<CoreMessage>) { pub(crate) fn start(config: Config, rx: Receiver<CoreMessage>, tx: Sender<CoreMessage>) {
spawn(async move { spawn(async move {
info!("Driver started."); trace!("Driver started.");
runner(config, rx, tx).await; runner(config, rx, tx).await;
info!("Driver finished."); trace!("Driver finished.");
}); });
} }
@@ -42,17 +42,17 @@ fn start_internals(core: Sender<CoreMessage>, config: Config) -> Interconnect {
let ic = interconnect.clone(); let ic = interconnect.clone();
spawn(async move { spawn(async move {
info!("Event processor started."); trace!("Event processor started.");
events::runner(ic, evt_rx).await; events::runner(ic, evt_rx).await;
info!("Event processor finished."); trace!("Event processor finished.");
}); });
let ic = interconnect.clone(); let ic = interconnect.clone();
let handle = Handle::current(); let handle = Handle::current();
std::thread::spawn(move || { std::thread::spawn(move || {
info!("Mixer started."); trace!("Mixer started.");
mixer::runner(ic, mix_rx, handle, config); mixer::runner(ic, mix_rx, handle, config);
info!("Mixer finished."); trace!("Mixer finished.");
}); });
interconnect interconnect
@@ -204,6 +204,6 @@ async fn runner(mut config: Config, rx: Receiver<CoreMessage>, tx: Sender<CoreMe
} }
} }
info!("Main thread exited"); trace!("Main thread exited");
interconnect.poison_all(); interconnect.poison_all();
} }

10
src/driver/tasks/udp_rx.rs
View File

@@ -25,7 +25,7 @@ use std::{collections::HashMap, sync::Arc};
use tokio::{net::UdpSocket, select}; use tokio::{net::UdpSocket, select};
#[cfg(feature = "tokio-02-marker")] #[cfg(feature = "tokio-02-marker")]
use tokio_compat::{net::udp::RecvHalf, select}; use tokio_compat::{net::udp::RecvHalf, select};
use tracing::{error, info, instrument, warn}; use tracing::{error, instrument, trace, warn};
use xsalsa20poly1305::XSalsa20Poly1305 as Cipher; use xsalsa20poly1305::XSalsa20Poly1305 as Cipher;
#[derive(Debug)] #[derive(Debug)]
@@ -401,7 +401,7 @@ pub(crate) async fn runner(
config: Config, config: Config,
udp_socket: Arc<UdpSocket>, udp_socket: Arc<UdpSocket>,
) { ) {
info!("UDP receive handle started."); trace!("UDP receive handle started.");
let mut state = UdpRx { let mut state = UdpRx {
cipher, cipher,
@@ -414,7 +414,7 @@ pub(crate) async fn runner(
state.run(&mut interconnect).await; state.run(&mut interconnect).await;
info!("UDP receive handle stopped."); trace!("UDP receive handle stopped.");
} }
#[cfg(feature = "tokio-02-marker")] #[cfg(feature = "tokio-02-marker")]
@@ -426,7 +426,7 @@ pub(crate) async fn runner(
config: Config, config: Config,
udp_socket: RecvHalf, udp_socket: RecvHalf,
) { ) {
info!("UDP receive handle started."); trace!("UDP receive handle started.");
let mut state = UdpRx { let mut state = UdpRx {
cipher, cipher,
@@ -439,7 +439,7 @@ pub(crate) async fn runner(
state.run(&mut interconnect).await; state.run(&mut interconnect).await;
info!("UDP receive handle stopped."); trace!("UDP receive handle stopped.");
} }
#[inline] #[inline]

10
src/driver/tasks/udp_tx.rs
View File

@@ -13,7 +13,7 @@ use tokio_compat::{
net::udp::SendHalf, net::udp::SendHalf,
time::{timeout_at, Instant}, time::{timeout_at, Instant},
}; };
use tracing::{error, info, instrument, trace}; use tracing::{error, instrument, trace};
struct UdpTx { struct UdpTx {
ssrc: u32, ssrc: u32,
@@ -65,7 +65,7 @@ impl UdpTx {
#[cfg(not(feature = "tokio-02-marker"))] #[cfg(not(feature = "tokio-02-marker"))]
#[instrument(skip(udp_msg_rx))] #[instrument(skip(udp_msg_rx))]
pub(crate) async fn runner(udp_msg_rx: Receiver<UdpTxMessage>, ssrc: u32, udp_tx: Arc<UdpSocket>) { pub(crate) async fn runner(udp_msg_rx: Receiver<UdpTxMessage>, ssrc: u32, udp_tx: Arc<UdpSocket>) {
info!("UDP transmit handle started."); trace!("UDP transmit handle started.");
let mut txer = UdpTx { let mut txer = UdpTx {
ssrc, ssrc,
@@ -75,13 +75,13 @@ pub(crate) async fn runner(udp_msg_rx: Receiver<UdpTxMessage>, ssrc: u32, udp_tx
txer.run().await; txer.run().await;
info!("UDP transmit handle stopped."); trace!("UDP transmit handle stopped.");
} }
#[cfg(feature = "tokio-02-marker")] #[cfg(feature = "tokio-02-marker")]
#[instrument(skip(udp_msg_rx))] #[instrument(skip(udp_msg_rx))]
pub(crate) async fn runner(udp_msg_rx: Receiver<UdpTxMessage>, ssrc: u32, udp_tx: SendHalf) { pub(crate) async fn runner(udp_msg_rx: Receiver<UdpTxMessage>, ssrc: u32, udp_tx: SendHalf) {
info!("UDP transmit handle started."); trace!("UDP transmit handle started.");
let mut txer = UdpTx { let mut txer = UdpTx {
ssrc, ssrc,
@@ -91,5 +91,5 @@ pub(crate) async fn runner(udp_msg_rx: Receiver<UdpTxMessage>, ssrc: u32, udp_tx
txer.run().await; txer.run().await;
info!("UDP transmit handle stopped."); trace!("UDP transmit handle stopped.");
} }

10
src/driver/tasks/ws.rs
View File

@@ -27,7 +27,7 @@ use tokio_compat::{
select, select,
time::{delay_until as sleep_until, Instant}, time::{delay_until as sleep_until, Instant},
}; };
use tracing::{error, info, instrument, trace, warn}; use tracing::{debug, info, instrument, trace, warn};
struct AuxNetwork { struct AuxNetwork {
rx: Receiver<WsMessage>, rx: Receiver<WsMessage>,
@@ -85,7 +85,7 @@ impl AuxNetwork {
ws_msg = self.ws_client.recv_json_no_timeout(), if !self.dont_send => { ws_msg = self.ws_client.recv_json_no_timeout(), if !self.dont_send => {
ws_error = match ws_msg { ws_error = match ws_msg {
Err(WsError::Json(e)) => { Err(WsError::Json(e)) => {
warn!("Unexpected JSON {:?}.", e); debug!("Unexpected JSON {:?}.", e);
false false
}, },
Err(e) => { Err(e) => {
@@ -218,11 +218,11 @@ pub(crate) async fn runner(
ssrc: u32, ssrc: u32,
heartbeat_interval: f64, heartbeat_interval: f64,
) { ) {
info!("WS thread started."); trace!("WS thread started.");
let mut aux = AuxNetwork::new(evt_rx, ws_client, ssrc, heartbeat_interval); let mut aux = AuxNetwork::new(evt_rx, ws_client, ssrc, heartbeat_interval);
aux.run(&mut interconnect).await; aux.run(&mut interconnect).await;
info!("WS thread finished."); trace!("WS thread finished.");
} }
fn ws_error_is_not_final(err: WsError) -> bool { fn ws_error_is_not_final(err: WsError) -> bool {
@@ -237,7 +237,7 @@ fn ws_error_is_not_final(err: WsError) -> bool {
_ => true, _ => true,
}, },
e => { e => {
error!("Error sending/receiving ws {:?}.", e); debug!("Error sending/receiving ws {:?}.", e);
true true
}, },
} }

9
src/ws.rs
View File

@@ -26,7 +26,7 @@ use serde_json::Error as JsonError;
use tokio::time::{timeout, Duration}; use tokio::time::{timeout, Duration};
#[cfg(feature = "tokio-02-marker")] #[cfg(feature = "tokio-02-marker")]
use tokio_compat::time::{timeout, Duration}; use tokio_compat::time::{timeout, Duration};
use tracing::{instrument, warn}; use tracing::instrument;
pub type WsStream = WebSocketStream<ConnectStream>; pub type WsStream = WebSocketStream<ConnectStream>;
@@ -130,12 +130,7 @@ impl SenderExt for WsStream {
#[inline] #[inline]
pub(crate) fn convert_ws_message(message: Option<Message>) -> Result<Option<Event>> { pub(crate) fn convert_ws_message(message: Option<Message>) -> Result<Option<Event>> {
Ok(match message { Ok(match message {
Some(Message::Text(payload)) => Some(Message::Text(payload)) => serde_json::from_str(&payload).map(Some)?,
serde_json::from_str(&payload).map(Some).map_err(|why| {
warn!("Err deserializing text: {:?}; text: {}", why, payload,);
why
})?,
Some(Message::Binary(bytes)) => { Some(Message::Binary(bytes)) => {
return Err(Error::UnexpectedBinaryMessage(bytes)); return Err(Error::UnexpectedBinaryMessage(bytes));
}, },