admin command to change tracing log level dynamically

Signed-off-by: strawberry <strawberry@puppygock.gay>
This commit is contained in:
strawberry 2024-04-07 00:13:47 -04:00 committed by June
parent a83da4f17b
commit 7f14c08c34
5 changed files with 142 additions and 26 deletions

View file

@ -206,7 +206,13 @@ struct CheckForUpdatesResponse {
impl KeyValueDatabase { impl KeyValueDatabase {
/// Load an existing database or create a new one. /// Load an existing database or create a new one.
#[allow(clippy::too_many_lines)] #[allow(clippy::too_many_lines)]
pub async fn load_or_create(config: Config) -> Result<()> { pub async fn load_or_create(
config: Config,
tracing_reload_handler: tracing_subscriber::reload::Handle<
tracing_subscriber::EnvFilter,
tracing_subscriber::Registry,
>,
) -> Result<()> {
Self::check_db_setup(&config)?; Self::check_db_setup(&config)?;
if !Path::new(&config.database_path).exists() { if !Path::new(&config.database_path).exists() {
@ -369,7 +375,7 @@ impl KeyValueDatabase {
let db = Box::leak(db_raw); let db = Box::leak(db_raw);
let services_raw = Box::new(Services::build(db, &config)?); let services_raw = Box::new(Services::build(db, &config, tracing_reload_handler)?);
// This is the first and only time we initialize the SERVICE static // This is the first and only time we initialize the SERVICE static
*SERVICES.write().unwrap() = Some(Box::leak(services_raw)); *SERVICES.write().unwrap() = Some(Box::leak(services_raw));

View file

@ -38,7 +38,7 @@ use tower_http::{
ServiceBuilderExt as _, ServiceBuilderExt as _,
}; };
use tracing::{debug, error, info, warn, Level}; use tracing::{debug, error, info, warn, Level};
use tracing_subscriber::{prelude::*, EnvFilter}; use tracing_subscriber::{prelude::*, reload, EnvFilter, Registry};
mod routes; mod routes;
@ -51,6 +51,8 @@ struct Server {
runtime: tokio::runtime::Runtime, runtime: tokio::runtime::Runtime,
tracing_reload_handle: reload::Handle<EnvFilter, Registry>,
#[cfg(feature = "sentry_telemetry")] #[cfg(feature = "sentry_telemetry")]
_sentry_guard: Option<sentry::ClientInitGuard>, _sentry_guard: Option<sentry::ClientInitGuard>,
} }
@ -267,7 +269,7 @@ async fn stop(_server: &Server) -> io::Result<()> {
/// Async initializations /// Async initializations
async fn start(server: &Server) -> Result<(), Error> { async fn start(server: &Server) -> Result<(), Error> {
let db_load_time = std::time::Instant::now(); let db_load_time = std::time::Instant::now();
KeyValueDatabase::load_or_create(server.config.clone()).await?; KeyValueDatabase::load_or_create(server.config.clone(), server.tracing_reload_handle.clone()).await?;
info!("Database took {:?} to load", db_load_time.elapsed()); info!("Database took {:?} to load", db_load_time.elapsed());
Ok(()) Ok(())
@ -427,15 +429,24 @@ fn init(args: clap::Args) -> Result<Server, Error> {
None None
}; };
if config.allow_jaeger { let tracing_reload_handle;
#[cfg(feature = "perf_measurements")] #[cfg(feature = "perf_measurements")]
init_tracing_jaeger(&config); {
tracing_reload_handle = if config.allow_jaeger {
init_tracing_jaeger(&config)
} else if config.tracing_flame { } else if config.tracing_flame {
#[cfg(feature = "perf_measurements")] #[cfg(feature = "perf_measurements")]
init_tracing_flame(&config); init_tracing_flame(&config)
} else { } else {
init_tracing_sub(&config); init_tracing_sub(&config)
} };
};
#[cfg(not(feature = "perf_measurements"))]
{
tracing_reload_handle = init_tracing_sub(&config);
};
info!( info!(
server_name = ?config.server_name, server_name = ?config.server_name,
@ -459,6 +470,8 @@ fn init(args: clap::Args) -> Result<Server, Error> {
.build() .build()
.unwrap(), .unwrap(),
tracing_reload_handle,
#[cfg(feature = "sentry_telemetry")] #[cfg(feature = "sentry_telemetry")]
_sentry_guard: sentry_guard, _sentry_guard: sentry_guard,
}) })
@ -481,8 +494,8 @@ fn init_sentry(config: &Config) -> sentry::ClientInitGuard {
)) ))
} }
fn init_tracing_sub(config: &Config) { fn init_tracing_sub(config: &Config) -> reload::Handle<EnvFilter, Registry> {
let registry = tracing_subscriber::Registry::default(); let registry = Registry::default();
let fmt_layer = tracing_subscriber::fmt::Layer::new(); let fmt_layer = tracing_subscriber::fmt::Layer::new();
let filter_layer = match EnvFilter::try_new(&config.log) { let filter_layer = match EnvFilter::try_new(&config.log) {
Ok(s) => s, Ok(s) => s,
@ -492,6 +505,8 @@ fn init_tracing_sub(config: &Config) {
}, },
}; };
let (reload_filter, reload_handle) = reload::Layer::new(filter_layer);
#[cfg(feature = "sentry_telemetry")] #[cfg(feature = "sentry_telemetry")]
let sentry_layer = sentry_tracing::layer(); let sentry_layer = sentry_tracing::layer();
@ -501,7 +516,7 @@ fn init_tracing_sub(config: &Config) {
#[cfg(feature = "sentry_telemetry")] #[cfg(feature = "sentry_telemetry")]
{ {
subscriber = registry subscriber = registry
.with(filter_layer) .with(reload_filter)
.with(fmt_layer) .with(fmt_layer)
.with(sentry_layer); .with(sentry_layer);
}; };
@ -509,14 +524,16 @@ fn init_tracing_sub(config: &Config) {
#[allow(clippy::unnecessary_operation)] // error[E0658]: attributes on expressions are experimental #[allow(clippy::unnecessary_operation)] // error[E0658]: attributes on expressions are experimental
#[cfg(not(feature = "sentry_telemetry"))] #[cfg(not(feature = "sentry_telemetry"))]
{ {
subscriber = registry.with(filter_layer).with(fmt_layer); subscriber = registry.with(reload_filter).with(fmt_layer);
}; };
tracing::subscriber::set_global_default(subscriber).unwrap(); tracing::subscriber::set_global_default(subscriber).unwrap();
reload_handle
} }
#[cfg(feature = "perf_measurements")] #[cfg(feature = "perf_measurements")]
fn init_tracing_jaeger(config: &Config) { fn init_tracing_jaeger(config: &Config) -> reload::Handle<EnvFilter, Registry> {
opentelemetry::global::set_text_map_propagator(opentelemetry_jaeger::Propagator::new()); opentelemetry::global::set_text_map_propagator(opentelemetry_jaeger::Propagator::new());
let tracer = opentelemetry_jaeger::new_agent_pipeline() let tracer = opentelemetry_jaeger::new_agent_pipeline()
.with_auto_split_batch(true) .with_auto_split_batch(true)
@ -533,22 +550,30 @@ fn init_tracing_jaeger(config: &Config) {
}, },
}; };
let subscriber = tracing_subscriber::Registry::default() let (reload_filter, reload_handle) = reload::Layer::new(filter_layer);
.with(filter_layer)
.with(telemetry); let subscriber = Registry::default().with(reload_filter).with(telemetry);
tracing::subscriber::set_global_default(subscriber).unwrap(); tracing::subscriber::set_global_default(subscriber).unwrap();
reload_handle
} }
#[cfg(feature = "perf_measurements")] #[cfg(feature = "perf_measurements")]
fn init_tracing_flame(_config: &Config) { fn init_tracing_flame(_config: &Config) -> reload::Handle<EnvFilter, Registry> {
let registry = tracing_subscriber::Registry::default(); let registry = Registry::default();
let (flame_layer, _guard) = tracing_flame::FlameLayer::with_file("./tracing.folded").unwrap(); let (flame_layer, _guard) = tracing_flame::FlameLayer::with_file("./tracing.folded").unwrap();
let flame_layer = flame_layer.with_empty_samples(false); let flame_layer = flame_layer.with_empty_samples(false);
let filter_layer = EnvFilter::new("trace,h2=off"); let filter_layer = EnvFilter::new("trace,h2=off");
let subscriber = registry.with(filter_layer).with(flame_layer); let (reload_filter, reload_handle) = reload::Layer::new(filter_layer);
let subscriber = registry.with(reload_filter).with(flame_layer);
tracing::subscriber::set_global_default(subscriber).unwrap(); tracing::subscriber::set_global_default(subscriber).unwrap();
reload_handle
} }
// This is needed for opening lots of file descriptors, which tends to // This is needed for opening lots of file descriptors, which tends to

View file

@ -7,6 +7,7 @@ use ruma::{
}; };
use tokio::sync::RwLock; use tokio::sync::RwLock;
use tracing::{debug, error, info, warn}; use tracing::{debug, error, info, warn};
use tracing_subscriber::EnvFilter;
use crate::{api::server_server::parse_incoming_pdu, services, utils::HtmlEscape, Error, PduEvent, Result}; use crate::{api::server_server::parse_incoming_pdu, services, utils::HtmlEscape, Error, PduEvent, Result};
@ -71,6 +72,18 @@ pub(crate) enum DebugCommand {
/// - Forces device lists for all local and remote users to be updated (as /// - Forces device lists for all local and remote users to be updated (as
/// having new keys available) /// having new keys available)
ForceDeviceListUpdates, ForceDeviceListUpdates,
/// - Change tracing log level/filter on the fly
///
/// This accepts the same format as the `log` config option.
ChangeLogLevel {
/// Log level/filter
filter: Option<String>,
/// Resets the log level/filter to the one in your config
#[arg(short, long)]
reset: bool,
},
} }
pub(crate) async fn process(command: DebugCommand, body: Vec<&str>) -> Result<RoomMessageEventContent> { pub(crate) async fn process(command: DebugCommand, body: Vec<&str>) -> Result<RoomMessageEventContent> {
@ -354,5 +367,66 @@ pub(crate) async fn process(command: DebugCommand, body: Vec<&str>) -> Result<Ro
} }
RoomMessageEventContent::text_plain("Marked all devices for all users as having new keys to update") RoomMessageEventContent::text_plain("Marked all devices for all users as having new keys to update")
}, },
DebugCommand::ChangeLogLevel {
filter,
reset,
} => {
if reset {
let old_filter_layer = match EnvFilter::try_new(&services().globals.config.log) {
Ok(s) => s,
Err(e) => {
return Ok(RoomMessageEventContent::text_plain(format!(
"Log level from config appears to be invalid now: {e}"
)));
},
};
match services()
.globals
.tracing_reload_handle
.modify(|filter| *filter = old_filter_layer)
{
Ok(()) => {
return Ok(RoomMessageEventContent::text_plain(format!(
"Successfully changed log level back to config value {}",
services().globals.config.log
)));
},
Err(e) => {
return Ok(RoomMessageEventContent::text_plain(format!(
"Failed to modify and reload the global tracing log level: {e}"
)));
},
}
}
if let Some(filter) = filter {
let new_filter_layer = match EnvFilter::try_new(filter) {
Ok(s) => s,
Err(e) => {
return Ok(RoomMessageEventContent::text_plain(format!(
"Invalid log level filter specified: {e}"
)));
},
};
match services()
.globals
.tracing_reload_handle
.modify(|filter| *filter = new_filter_layer)
{
Ok(()) => {
return Ok(RoomMessageEventContent::text_plain("Successfully changed log level"));
},
Err(e) => {
return Ok(RoomMessageEventContent::text_plain(format!(
"Failed to modify and reload the global tracing log level: {e}"
)));
},
}
}
return Ok(RoomMessageEventContent::text_plain("No log level was specified."));
},
}) })
} }

View file

@ -26,6 +26,7 @@ use ruma::{
}; };
use tokio::sync::{broadcast, watch::Receiver, Mutex, RwLock, Semaphore}; use tokio::sync::{broadcast, watch::Receiver, Mutex, RwLock, Semaphore};
use tracing::{error, info}; use tracing::{error, info};
use tracing_subscriber::{EnvFilter, Registry};
use crate::{services, Config, Result}; use crate::{services, Config, Result};
@ -42,6 +43,7 @@ type SyncHandle = (
pub struct Service<'a> { pub struct Service<'a> {
pub db: &'static dyn Data, pub db: &'static dyn Data,
pub tracing_reload_handle: tracing_subscriber::reload::Handle<EnvFilter, Registry>,
pub config: Config, pub config: Config,
keypair: Arc<ruma::signatures::Ed25519KeyPair>, keypair: Arc<ruma::signatures::Ed25519KeyPair>,
jwt_decoding_key: Option<jsonwebtoken::DecodingKey>, jwt_decoding_key: Option<jsonwebtoken::DecodingKey>,
@ -94,7 +96,10 @@ impl Default for RotationHandler {
} }
impl Service<'_> { impl Service<'_> {
pub fn load(db: &'static dyn Data, config: &Config) -> Result<Self> { pub fn load(
db: &'static dyn Data, config: &Config,
tracing_reload_handle: tracing_subscriber::reload::Handle<EnvFilter, Registry>,
) -> Result<Self> {
let keypair = db.load_keypair(); let keypair = db.load_keypair();
let keypair = match keypair { let keypair = match keypair {
@ -135,7 +140,9 @@ impl Service<'_> {
argon2::Version::default(), argon2::Version::default(),
argon2::Params::new(19456, 2, 1, None).expect("valid parameters"), argon2::Params::new(19456, 2, 1, None).expect("valid parameters"),
); );
let mut s = Self { let mut s = Self {
tracing_reload_handle,
db, db,
config: config.clone(), config: config.clone(),
keypair: Arc::new(keypair), keypair: Arc::new(keypair),

View file

@ -56,6 +56,10 @@ impl Services<'_> {
+ 'static, + 'static,
>( >(
db: &'static D, config: &Config, db: &'static D, config: &Config,
tracing_reload_handle: tracing_subscriber::reload::Handle<
tracing_subscriber::EnvFilter,
tracing_subscriber::Registry,
>,
) -> Result<Self> { ) -> Result<Self> {
Ok(Self { Ok(Self {
appservice: appservice::Service::build(db)?, appservice: appservice::Service::build(db)?,
@ -166,7 +170,7 @@ impl Services<'_> {
}, },
sending: sending::Service::build(db, config), sending: sending::Service::build(db, config),
globals: globals::Service::load(db, config)?, globals: globals::Service::load(db, config, tracing_reload_handle)?,
}) })
} }