Skip to content
Merged
101 changes: 98 additions & 3 deletions crates/cli/src/subcommands/logs.rs
Original file line number Diff line number Diff line change
Expand Up @@ -48,6 +48,28 @@ pub fn cli() -> clap::Command {
.value_parser(clap::value_parser!(Format))
.help("Output format for the logs")
)
.arg(
Arg::new("level")
.long("level")
.short('l')
.value_parser(clap::value_parser!(LogLevel))
.help("Minimum log level to display")
.long_help(
"Filter logs by severity level. Only messages at the specified level or higher \
will be shown. Levels from least to most severe: trace, debug, info, warn, error, panic.",
),
)
.arg(
Arg::new("level_exact")
.long("level-exact")
.requires("level")
.action(ArgAction::SetTrue)
.help("Show only logs at exactly the specified level")
.long_help(
"When combined with --level, show only logs at exactly the specified level \
instead of that level and above.",
),
)
.arg(common_args::yes())
.arg(
Arg::new("no_config")
Expand All @@ -58,7 +80,7 @@ pub fn cli() -> clap::Command {
.after_help("Run `spacetime help logs` for more detailed information.\n")
}

#[derive(serde::Deserialize)]
#[derive(Clone, Copy, serde::Deserialize)]
pub enum LogLevel {
Error,
Warn,
Expand All @@ -68,6 +90,43 @@ pub enum LogLevel {
Panic,
}

impl LogLevel {
/// Returns a numeric severity value. Higher means more severe.
fn severity(self) -> u8 {
match self {
LogLevel::Trace => 0,
LogLevel::Debug => 1,
LogLevel::Info => 2,
LogLevel::Warn => 3,
LogLevel::Error => 4,
LogLevel::Panic => 5,
}
}
}

impl clap::ValueEnum for LogLevel {
fn value_variants<'a>() -> &'a [Self] {
&[
Self::Trace,
Self::Debug,
Self::Info,
Self::Warn,
Self::Error,
Self::Panic,
]
}
fn to_possible_value(&self) -> Option<clap::builder::PossibleValue> {
match self {
Self::Trace => Some(clap::builder::PossibleValue::new("trace")),
Self::Debug => Some(clap::builder::PossibleValue::new("debug")),
Self::Info => Some(clap::builder::PossibleValue::new("info")),
Self::Warn => Some(clap::builder::PossibleValue::new("warn")),
Self::Error => Some(clap::builder::PossibleValue::new("error")),
Self::Panic => Some(clap::builder::PossibleValue::new("panic")),
}
}
}

/// Sentinel value used for injected system logs.
///
/// Keep this in sync with the constants in `spacetimedb_core::database_logger::Record`.
Expand Down Expand Up @@ -140,6 +199,8 @@ pub async fn exec(mut config: Config, args: &ArgMatches) -> Result<(), anyhow::E
let mut num_lines = args.get_one::<u32>("num_lines").copied();
let follow = args.get_flag("follow");
let format = *args.get_one::<Format>("format").unwrap();
let min_level = args.get_one::<LogLevel>("level").copied();
let level_exact = args.get_flag("level_exact");

let auth_header = get_auth_header(&mut config, false, server, !force).await?;

Expand All @@ -165,8 +226,22 @@ pub async fn exec(mut config: Config, args: &ArgMatches) -> Result<(), anyhow::E

if format == Format::Json {
let mut stdout = tokio::io::stdout();
while let Some(chunk) = res.chunk().await? {
stdout.write_all(&chunk).await?;
if min_level.is_none() {
// Fast path: no filtering, stream raw bytes.
while let Some(chunk) = res.chunk().await? {
stdout.write_all(&chunk).await?;
}
} else {
// Parse each line to apply level filtering, then re-emit as JSON.
let mut rdr = res.bytes_stream().map_err(io::Error::other).into_async_read();
let mut line = String::new();
while rdr.read_line(&mut line).await? != 0 {
let record = serde_json::from_str::<Record<'_>>(&line)?;
if should_display(record.level, min_level, level_exact) {
stdout.write_all(line.as_bytes()).await?;
}
line.clear();
}
}
return Ok(());
}
Expand All @@ -184,6 +259,12 @@ pub async fn exec(mut config: Config, args: &ArgMatches) -> Result<(), anyhow::E
while rdr.read_line(&mut line).await? != 0 {
let record = serde_json::from_str::<Record<'_>>(&line)?;

// Apply log level filtering.
if !should_display(record.level, min_level, level_exact) {
line.clear();
continue;
}

if let Some(ts) = record.ts {
out.set_color(ColorSpec::new().set_dimmed(true))?;
write!(out, "{ts:?} ")?;
Expand Down Expand Up @@ -270,3 +351,17 @@ pub async fn exec(mut config: Config, args: &ArgMatches) -> Result<(), anyhow::E

Ok(())
}

/// Returns true if the record should be displayed given the filter settings.
fn should_display(record_level: LogLevel, min_level: Option<LogLevel>, level_exact: bool) -> bool {
match min_level {
None => true,
Some(min) => {
if level_exact {
record_level.severity() == min.severity()
} else {
record_level.severity() >= min.severity()
}
}
}
}
8 changes: 8 additions & 0 deletions crates/smoketests/modules/Cargo.lock

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

3 changes: 3 additions & 0 deletions crates/smoketests/modules/Cargo.toml
Original file line number Diff line number Diff line change
Expand Up @@ -75,6 +75,9 @@ members = [
"client-connection-reject",
"client-connection-disconnect-panic",

# Log filtering tests
"logs-level-filter",

# Misc tests
"namespaces",
"new-user-flow",
Expand Down
12 changes: 12 additions & 0 deletions crates/smoketests/modules/logs-level-filter/Cargo.toml
Original file line number Diff line number Diff line change
@@ -0,0 +1,12 @@
[package]
name = "smoketest-module-logs-level-filter"
version = "0.1.0"
edition = "2021"
publish = false

[lib]
crate-type = ["cdylib"]

[dependencies]
spacetimedb.workspace = true
log.workspace = true
10 changes: 10 additions & 0 deletions crates/smoketests/modules/logs-level-filter/src/lib.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,10 @@
use spacetimedb::ReducerContext;

#[spacetimedb::reducer]
pub fn log_all_levels(_ctx: &ReducerContext) {
log::trace!("msg-trace");
log::debug!("msg-debug");
log::info!("msg-info");
log::warn!("msg-warn");
log::error!("msg-error");
}
88 changes: 88 additions & 0 deletions crates/smoketests/tests/smoketests/logs_level_filter.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,88 @@
use spacetimedb_smoketests::Smoketest;

fn logs_filtered(test: &Smoketest, n: usize, extra_args: &[&str]) -> Vec<serde_json::Value> {
let identity = test.database_identity.as_ref().expect("No database published");
let n_str = n.to_string();

let mut args = vec!["logs", "--server", &test.server_url, "--format=json", "-n", &n_str];
args.extend_from_slice(extra_args);
args.push("--");
args.push(identity);

let output = test.spacetime(&args).expect("spacetime logs failed");
output
.lines()
.filter(|line| !line.trim().is_empty())
.map(|line| serde_json::from_str(line).expect("Failed to parse log record"))
.collect()
}

fn messages(records: &[serde_json::Value]) -> Vec<String> {
records
.iter()
.filter_map(|r| r.get("message").and_then(|m| m.as_str()).map(String::from))
.collect()
}

/// Without --level, all log levels are returned.
#[test]
fn test_logs_no_filter() {
let test = Smoketest::builder().precompiled_module("logs-level-filter").build();

test.call("log_all_levels", &[]).unwrap();

let msgs = messages(&logs_filtered(&test, 100, &[]));
assert!(msgs.iter().any(|m| m == "msg-trace"), "missing trace: {msgs:?}");
assert!(msgs.iter().any(|m| m == "msg-debug"), "missing debug: {msgs:?}");
assert!(msgs.iter().any(|m| m == "msg-info"), "missing info: {msgs:?}");
assert!(msgs.iter().any(|m| m == "msg-warn"), "missing warn: {msgs:?}");
assert!(msgs.iter().any(|m| m == "msg-error"), "missing error: {msgs:?}");
}

/// --level filters to that level and above.
#[test]
fn test_logs_level_minimum() {
let test = Smoketest::builder().precompiled_module("logs-level-filter").build();

test.call("log_all_levels", &[]).unwrap();

// --level warn: only warn and error
let msgs = messages(&logs_filtered(&test, 100, &["--level", "warn"]));
assert!(!msgs.iter().any(|m| m == "msg-trace"), "unexpected trace: {msgs:?}");
assert!(!msgs.iter().any(|m| m == "msg-debug"), "unexpected debug: {msgs:?}");
assert!(!msgs.iter().any(|m| m == "msg-info"), "unexpected info: {msgs:?}");
assert!(msgs.iter().any(|m| m == "msg-warn"), "missing warn: {msgs:?}");
assert!(msgs.iter().any(|m| m == "msg-error"), "missing error: {msgs:?}");

// --level error: only error
let msgs = messages(&logs_filtered(&test, 100, &["--level", "error"]));
assert!(!msgs.iter().any(|m| m == "msg-trace"), "unexpected trace: {msgs:?}");
assert!(!msgs.iter().any(|m| m == "msg-debug"), "unexpected debug: {msgs:?}");
assert!(!msgs.iter().any(|m| m == "msg-info"), "unexpected info: {msgs:?}");
assert!(!msgs.iter().any(|m| m == "msg-warn"), "unexpected warn: {msgs:?}");
assert!(msgs.iter().any(|m| m == "msg-error"), "missing error: {msgs:?}");
}

/// --level-exact shows only the specified level.
#[test]
fn test_logs_level_exact() {
let test = Smoketest::builder().precompiled_module("logs-level-filter").build();

test.call("log_all_levels", &[]).unwrap();

// --level info --level-exact: only info
let msgs = messages(&logs_filtered(&test, 100, &["--level", "info", "--level-exact"]));
assert!(!msgs.iter().any(|m| m == "msg-trace"), "unexpected trace: {msgs:?}");
assert!(!msgs.iter().any(|m| m == "msg-debug"), "unexpected debug: {msgs:?}");
assert!(msgs.iter().any(|m| m == "msg-info"), "missing info: {msgs:?}");
assert!(!msgs.iter().any(|m| m == "msg-warn"), "unexpected warn: {msgs:?}");
assert!(!msgs.iter().any(|m| m == "msg-error"), "unexpected error: {msgs:?}");

// --level debug --level-exact: only debug
let msgs = messages(&logs_filtered(&test, 100, &["--level", "debug", "--level-exact"]));
assert!(!msgs.iter().any(|m| m == "msg-trace"), "unexpected trace: {msgs:?}");
assert!(msgs.iter().any(|m| m == "msg-debug"), "missing debug: {msgs:?}");
assert!(!msgs.iter().any(|m| m == "msg-info"), "unexpected info: {msgs:?}");
assert!(!msgs.iter().any(|m| m == "msg-warn"), "unexpected warn: {msgs:?}");
assert!(!msgs.iter().any(|m| m == "msg-error"), "unexpected error: {msgs:?}");
}
1 change: 1 addition & 0 deletions crates/smoketests/tests/smoketests/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@ mod domains;
mod fail_initial_publish;
mod filtering;
mod http_egress;
mod logs_level_filter;
mod module_nested_op;
mod modules;
mod namespaces;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -159,6 +159,11 @@ Run `spacetime help logs` for more detailed information.

Possible values: `text`, `json`

* `-l`, `--level <LEVEL>` — Filter logs by severity level. Only messages at the specified level or higher will be shown. Levels from least to most severe: trace, debug, info, warn, error, panic.

Possible values: `trace`, `debug`, `info`, `warn`, `error`, `panic`

* `--level-exact` — When combined with --level, show only logs at exactly the specified level instead of that level and above.
* `-y`, `--yes` — Run non-interactively wherever possible. This will answer "yes" to almost all prompts, but will sometimes answer "no" to preserve non-interactivity (e.g. when prompting whether to log in with spacetimedb.com).
* `--no-config` — Ignore spacetime.json configuration

Expand Down
Loading