From 93aa1b5900c14ddba973803f67a564bfe307620d Mon Sep 17 00:00:00 2001 From: LynithDev <61880709+LynithDev@users.noreply.github.com> Date: Thu, 6 Aug 2026 13:25:18 +0200 Subject: [PATCH] feat(logs): live launcher log console in its own window (#697) --- .../src/view/app/cluster/logs.rs | 151 +++++--- .../src/view/app/settings/developer.rs | 9 +- packages/oneclient_app/src/view/console.rs | 325 ++++++++++++++++++ packages/oneclient_app/src/view/mod.rs | 1 + packages/oneclient_cluster/src/logs/manage.rs | 19 +- packages/oneclient_cluster/src/logs/mod.rs | 13 +- packages/oneclient_core/src/logger.rs | 153 ++++++++- packages/oneclient_core/src/logger/console.rs | 142 ++++++++ 8 files changed, 755 insertions(+), 58 deletions(-) create mode 100644 packages/oneclient_app/src/view/console.rs create mode 100644 packages/oneclient_core/src/logger/console.rs diff --git a/packages/oneclient_app/src/view/app/cluster/logs.rs b/packages/oneclient_app/src/view/app/cluster/logs.rs index a7ac67e0..1f23ef88 100644 --- a/packages/oneclient_app/src/view/app/cluster/logs.rs +++ b/packages/oneclient_app/src/view/app/cluster/logs.rs @@ -2,7 +2,7 @@ use std::path::PathBuf; use std::sync::Arc; use freya::prelude::*; -use freya::query::MutationStateData; +use freya::query::{MutationStateData, UseQuery}; use freya::text_edit::Clipboard; use oneclient_common::search::SearchQuery; use oneclient_core::{LogFileInfo, LogKind, LogLevel}; @@ -12,9 +12,9 @@ use crate::components::{ TextInput, open_folder_button, }; use crate::hooks::{ - LogAction, UploadLogKeys, UseLogAction, UseUploadLog, invalidate_logs_queries, - try_cluster_logs, try_log_content, use_cluster_logs, use_dispatch, use_log_action, - use_log_content, use_upload_log, + ClusterLogsQuery, LogAction, UploadLogKeys, UseLogAction, UseUploadLog, + invalidate_logs_queries, try_cluster_logs, try_log_content, use_cluster_logs, use_dispatch, + use_log_action, use_log_content, use_upload_log, }; use crate::layout::cluster_content; use crate::theme::colors; @@ -65,10 +65,46 @@ enum Confirm { Upload, } +/// Which half of the cluster's files the picker is listing. +/// +/// Crash reports and ordinary logs answer different questions, and a crash +/// report buried among thirty rotated `.log.gz` files is one nobody finds. +#[derive(Clone, Copy, Debug, PartialEq, Eq)] +enum Category { + Logs, + CrashReports, +} + +impl Category { + fn accepts(self, kind: LogKind) -> bool { + kind.is_crash_report() == matches!(self, Self::CrashReports) + } + + fn label(self) -> &'static str { + match self { + Self::Logs => "Logs", + Self::CrashReports => "Crash reports", + } + } + + fn empty_label(self) -> &'static str { + match self { + Self::Logs => "No logs", + Self::CrashReports => "No crash reports", + } + } + + fn empty_note(self) -> &'static str { + match self { + Self::Logs => "No logs recorded yet", + Self::CrashReports => "No crash reports, which is the good outcome", + } + } +} + fn kind_badge(kind: LogKind) -> &'static str { match kind { LogKind::Game { .. } => "Game output", - LogKind::Launcher => "Launcher logs", LogKind::Minecraft => "Minecraft", LogKind::CrashReport => "Crash report", LogKind::Other => "Other", @@ -91,11 +127,15 @@ impl Component for ClusterLogs { let search = use_state(String::new); let level = use_state(|| LevelFilter::All); let confirm = use_state(|| None::); + let category = use_state(|| Category::Logs); let mut selected = use_state(PathBuf::new); let mut handled_upload = use_state(|| None::); + // Reads `category` as well as the query, so switching the picker to + // crash reports re-picks a file instead of leaving the viewer on a + // selection that is no longer in the list. use_side_effect(move || { - let files = try_cluster_logs(&logs_query).unwrap_or_default(); + let files = visible_files(&logs_query, *category.read()); if files.is_empty() { if !selected.peek().as_os_str().is_empty() { @@ -167,7 +207,7 @@ impl Component for ClusterLogs { }; let folder = cluster.dir().ok().map(|d| d.join("logs")); - let files = try_cluster_logs(&logs_query).unwrap_or_default(); + let files = visible_files(&logs_query, *category.read()); let has_log = !files.is_empty(); let selected_info = files.iter().find(|f| f.path == selected_path).cloned(); @@ -179,11 +219,6 @@ impl Component for ClusterLogs { .collect(), ); - let size_text = selected_info - .as_ref() - .map(|i| format!("{} on disk", format_size(i.size_bytes))) - .unwrap_or_else(|| "No logs recorded yet".to_string()); - let body = rect() .vertical() .width(Size::fill()) @@ -192,11 +227,10 @@ impl Component for ClusterLogs { .child(top_bar( files.clone(), selected_info.clone(), - size_text, - has_log, folder, selected, confirm, + category, )) .child( rect().width(Size::fill()).height(Size::flex(1.0)).child( @@ -214,19 +248,34 @@ impl Component for ClusterLogs { } } +/// The files the picker should be showing right now. +fn visible_files(query: &UseQuery, category: Category) -> Vec { + try_cluster_logs(query) + .unwrap_or_default() + .into_iter() + .filter(|file| category.accepts(file.kind)) + .collect() +} + fn top_bar( files: Vec, selected_info: Option, - size_text: String, - has_log: bool, folder: Option, selected: State, mut confirm: State>, + category: State, ) -> impl IntoElement { + let has_log = !files.is_empty(); + let picker_label = selected_info .as_ref() .map(|i| i.name.clone()) - .unwrap_or_else(|| "No logs".to_string()); + .unwrap_or_else(|| category.read().empty_label().to_string()); + + let size_text = selected_info + .as_ref() + .map(|i| format!("{} on disk", format_size(i.size_bytes))) + .unwrap_or_else(|| category.read().empty_note().to_string()); rect() .horizontal() @@ -238,7 +287,7 @@ fn top_bar( LogPicker { label: picker_label, files, - enabled: has_log, + category, on_select: (move |path: PathBuf| { let mut selected = selected; selected.set(path); @@ -349,7 +398,10 @@ fn viewer_header( struct LogPicker { label: String, files: Vec, - enabled: bool, + /// Owned by the page rather than by this component: the page filters + /// `files` by it and re-picks a selection when it changes, so both have to + /// be looking at the same value. + category: State, on_select: EventHandler, } @@ -361,13 +413,17 @@ impl Component for LogPicker { let a11y_id = use_a11y(); let focus = use_focus(a11y_id); - let enabled = self.enabled; + let category = self.category; let label_text = self.label.clone(); let files = self.files.clone(); let on_select = self.on_select.clone(); - let is_open = open() && enabled; + // Stays usable with an empty list: the category selector lives inside + // the panel, so a cluster with no crash reports still needs a way back + // to its logs. + let is_open = open(); let query = SearchQuery::new(&filter.read()); + let no_files = files.is_empty(); let rows: Vec = files .into_iter() .filter(|f| query.matches(&f.name) || query.matches(kind_badge(f.kind))) @@ -403,38 +459,29 @@ impl Component for LogPicker { .corner_radius(CornerRadius::new_all(9.)) .background(colors::component_bg()) .a11y_id(a11y_id) - .a11y_focusable(enabled) + .a11y_focusable(true) .a11y_role(AccessibilityRole::Button) .border(ui::border_all_color( 1., - if enabled && focus().is_focused() { + if focus().is_focused() { colors::brand() } else { colors::component_border() }, )) - .on_pointer_enter(move |_| { - if enabled { - Cursor::set(CursorIcon::Pointer) - } - }) + .on_pointer_enter(|_| Cursor::set(CursorIcon::Pointer)) .on_pointer_leave(|_| Cursor::set(CursorIcon::default())) .on_all_press(move |e: Event| { - if !enabled { - return; - } e.stop_propagation(); open.toggle(); }) .child( rect().width(Size::flex(1.0)).child( - label().text(label_text).font_size(13.).max_lines(1).color( - if enabled { - colors::fg_primary() - } else { - colors::fg_secondary().with_a(110) - }, - ), + label() + .text(label_text) + .font_size(13.) + .max_lines(1) + .color(colors::fg_primary()), ), ) .child( @@ -460,7 +507,9 @@ impl Component for LogPicker { rect() .margin(Gaps::new(4., 0., 0., 0.)) .width(Size::px(320.)) - .max_height(Size::px(360.)) + // Room for the category selector above the search + // box, on top of the list's own maximum. + .max_height(Size::px(400.)) .layer(Layer::OverlayLevel(12)) .vertical() .spacing(4.) @@ -469,6 +518,16 @@ impl Component for LogPicker { .border(ui::border_all_color(1., colors::component_border())) .background(colors::page_elevated()) .overflow(Overflow::Clip) + .child( + SegmentedControl::new(category) + .no_tint() + .equal_width(147.) + .segments( + [Category::Logs, Category::CrashReports] + .into_iter() + .map(|value| Segment::new(value).label(value.label())), + ), + ) .child( TextInput::new(filter) .auto_focus(true) @@ -480,6 +539,20 @@ impl Component for LogPicker { .into_element(), ), ) + .maybe_child(rows.is_empty().then(|| { + label() + .text(if no_files { + category.read().empty_note() + } else { + "No matches" + }) + .font_size(12.) + .width(Size::fill()) + .text_align(TextAlign::Center) + .padding(Gaps::new_symmetric(12., 0.)) + .color(colors::fg_secondary()) + .into_element() + })) .child( ScrollArea::new() .height(Size::px(list_h)) diff --git a/packages/oneclient_app/src/view/app/settings/developer.rs b/packages/oneclient_app/src/view/app/settings/developer.rs index 5cb498ff..3c28b5d1 100644 --- a/packages/oneclient_app/src/view/app/settings/developer.rs +++ b/packages/oneclient_app/src/view/app/settings/developer.rs @@ -6,6 +6,7 @@ use crate::Route; use crate::components::{IconType, link_button, toggle}; use crate::hooks::{use_browser_compat, use_dispatch, use_settings_snapshot}; use crate::view::app::settings::{section_header, settings_row}; +use crate::view::console::open_log_console; #[derive(PartialEq)] pub struct SettingsDeveloper; @@ -44,11 +45,17 @@ impl Component for SettingsDeveloper { )) .child(section_header("DEV TOOLS")) .child(settings_row( - IconType::Terminal, + IconType::Sliders04, "Log Debug Info", "WARNING! This requires a restart to apply. Logs out debug info.", toggle(log_debug), )) + .child(settings_row( + IconType::Terminal, + "Log Console", + "Stream the launcher's logs in a separate window. Nothing is captured while it is closed.", + link_button().on_press(move |_| open_log_console()), + )) .child(settings_row( IconType::CodeSnippet02, "Debug Page", diff --git a/packages/oneclient_app/src/view/console.rs b/packages/oneclient_app/src/view/console.rs new file mode 100644 index 00000000..5f117758 --- /dev/null +++ b/packages/oneclient_app/src/view/console.rs @@ -0,0 +1,325 @@ +//! The live launcher log console, in a window of its own. +//! +//! Freya gives every window its own component tree, so this one shares nothing +//! with the main window — no radio station, no query storage. All it needs is +//! the process-wide channel in [`oneclient_core::logger::console`], and that +//! channel only carries anything while this window is up. + +use std::collections::VecDeque; +use std::sync::{Arc, Mutex}; + +use freya::prelude::*; +use freya::winit::window::WindowId; +use oneclient_core::logger; +use oneclient_core::logger::console::{self, ConsoleLine}; +use tokio::sync::broadcast::error::RecvError; +use tracing::Level; + +use crate::components::{Button, Icon, IconType, LogViewer, Segment, SegmentedControl, TextInput}; +use crate::theme::colors; + +const WINDOW_TITLE: &str = "OneClient — Log Console"; + +/// How many lines the console keeps. +/// +/// Old lines are dropped from the front rather than kept forever: this window +/// can be left open for an entire session, and a launcher that leaks memory +/// while you watch it for leaks is not much use. +const MAX_LINES: usize = 5_000; + +/// Where the console window is in its lifecycle. +/// +/// `Opening` is not set by the task that asks for the window but cleared by the +/// window itself, so a task cancelled mid-launch — the settings page being +/// navigated away from, say — cannot strand the state. +enum ConsoleWindow { + Closed, + Opening, + Open(WindowId), +} + +static CONSOLE_WINDOW: Mutex = Mutex::new(ConsoleWindow::Closed); + +/// Opens the log console, or focuses it if it is already up. +pub fn open_log_console() { + { + let mut state = CONSOLE_WINDOW.lock().expect("console window state"); + match *state { + ConsoleWindow::Open(id) => { + Platform::get().focus_window(Some(id)); + return; + } + ConsoleWindow::Opening => return, + ConsoleWindow::Closed => *state = ConsoleWindow::Opening, + } + } + + // Taken here, in the caller's scope: the future below runs detached, and + // `Platform::get()` needs a component scope to resolve against. + let platform = Platform::get(); + spawn(async move { + platform.launch_window(window_config()).await; + }); +} + +fn window_config() -> WindowConfig { + WindowConfig::new_app(LogConsoleApp) + .with_title(WINDOW_TITLE) + .with_app_id(crate::constants::WINDOW_APP_ID) + .with_icon(LaunchConfig::window_icon(include_bytes!( + "../../icons/128x128.png" + ))) + .with_size(1000., 640.) + .with_min_size(520., 320.) + .with_background(colors::page()) + // Native decorations, unlike the main window's custom titlebar. This is + // a developer tool, and a second bespoke titlebar is not worth the code. + .with_decorations(true) + .with_window_handle(|window| { + *CONSOLE_WINDOW.lock().expect("console window state") = + ConsoleWindow::Open(window.id()); + }) + .with_on_close(|_, _| { + *CONSOLE_WINDOW.lock().expect("console window state") = ConsoleWindow::Closed; + CloseDecision::Close + }) +} + +struct LogConsoleApp; + +impl App for LogConsoleApp { + fn render(&self) -> impl IntoElement { + LogConsole + } +} + +/// The lowest severity the console shows. +/// +/// A floor rather than an exact match, unlike the cluster logs page: when you +/// are watching a stream go past, "warnings and worse" is the question you +/// actually have. +#[derive(Clone, Copy, Debug, PartialEq, Eq)] +enum Severity { + All, + Debug, + Info, + Warn, + Error, +} + +impl Severity { + fn floor(self) -> Option { + match self { + Self::All => None, + Self::Debug => Some(Level::DEBUG), + Self::Info => Some(Level::INFO), + Self::Warn => Some(Level::WARN), + Self::Error => Some(Level::ERROR), + } + } + + fn label(self) -> &'static str { + match self { + Self::All => "All", + Self::Debug => "Debug", + Self::Info => "Info", + Self::Warn => "Warnings", + Self::Error => "Errors", + } + } +} + +#[derive(PartialEq)] +struct LogConsole; + +impl Component for LogConsole { + fn render(&self) -> impl IntoElement { + let mut entries = use_state(VecDeque::::new); + let severity = use_state(|| Severity::All); + let search = use_state(String::new); + let directives = use_state(logger::active_directives); + let directives_error = use_state(|| None::); + + use_hook(move || { + spawn(async move { + // The subscription lives in this task and nowhere else, so when + // the window closes and its tree is dropped the receiver goes + // with it and capture switches itself off. + let mut subscription = console::subscribe(); + tracing::info!("live log console attached"); + + loop { + match subscription.recv().await { + Ok(line) => push(&mut entries, line), + Err(RecvError::Lagged(skipped)) => push( + &mut entries, + ConsoleLine { + level: Level::WARN, + text: format!( + "[console] dropped {skipped} lines, the console fell behind" + ) + .into(), + }, + ), + Err(RecvError::Closed) => break, + } + } + }) + }); + + let floor = severity.read().floor(); + let query = search.read().to_lowercase(); + let lines: Arc>> = Arc::new( + entries + .read() + .iter() + .filter(|line| floor.is_none_or(|floor| line.level <= floor)) + .filter(|line| query.is_empty() || line.text.to_lowercase().contains(&query)) + .map(|line| line.text.clone()) + .collect(), + ); + + rect() + .width(Size::fill()) + .height(Size::fill()) + .padding(Gaps::new_all(12.)) + .background(colors::page()) + .child( + LogViewer::new("Launcher logs", lines.clone()) + .streaming(true) + .header( + rect() + .vertical() + .width(Size::fill()) + .child(view_row(search, severity, lines.len(), entries)) + .child(crate::ui::divider()) + .child(filter_row(directives, directives_error)) + .child(crate::ui::divider()), + ), + ) + } +} + +fn push(entries: &mut State>, line: ConsoleLine) { + let mut entries = entries.write(); + while entries.len() >= MAX_LINES { + entries.pop_front(); + } + entries.push_back(line); +} + +/// What of the captured lines to show. Purely local: nothing here changes what +/// the launcher records. +fn view_row( + search: State, + severity: State, + shown: usize, + mut entries: State>, +) -> impl IntoElement { + rect() + .horizontal() + .width(Size::fill()) + .cross_align(Alignment::Center) + .content(Content::Flex) + .spacing(10.) + .padding(Gaps::new_symmetric(10., 14.)) + .child( + rect().width(Size::flex(1.0)).child( + TextInput::new(search) + .placeholder("Filter the stream...") + .leading( + Icon::new(IconType::SearchMd) + .size(15.) + .color(colors::fg_secondary()) + .into_element(), + ), + ), + ) + .child( + label() + .text(format!("{shown} lines")) + .font_size(11.) + .max_lines(1) + .color(colors::fg_secondary()), + ) + .child( + SegmentedControl::new(severity) + .no_tint() + .segments( + [ + Severity::All, + Severity::Error, + Severity::Warn, + Severity::Info, + Severity::Debug, + ] + .into_iter() + .map(|value| Segment::new(value).label(value.label())), + ) + .into_element(), + ) + .child( + Button::new() + .secondary() + .on_press(move |_| entries.write().clear()) + .child(Icon::new(IconType::Trash01).size(15.)) + .text("Clear"), + ) + .into_element() +} + +/// The `EnvFilter` directives the whole launcher is running under. +/// +/// This is the half that matters: the view filter above can only narrow what +/// was already captured, whereas applying here reloads the subscriber's filter, +/// so a target the launcher was not recording at all starts arriving. +fn filter_row(directives: State, mut error: State>) -> impl IntoElement { + let apply = move |_| match logger::set_filter(&directives.read()) { + Ok(()) => error.set(None), + Err(err) => error.set(Some(err.to_string())), + }; + + let mut reset = directives; + let row = rect() + .horizontal() + .width(Size::fill()) + .cross_align(Alignment::Center) + .content(Content::Flex) + .spacing(10.) + .padding(Gaps::new_symmetric(10., 14.)) + .child( + label() + .text("Capture") + .font_size(11.) + .max_lines(1) + .color(colors::fg_secondary()), + ) + .child( + rect() + .width(Size::flex(1.0)) + .child(TextInput::new(directives).placeholder("RUST_LOG directives...")), + ) + .child( + Button::new() + .secondary() + .on_press(move |_| reset.set(logger::default_directives())) + .text("Defaults"), + ) + .child(Button::new().primary().on_press(apply).text("Apply")); + + rect() + .vertical() + .width(Size::fill()) + .child(row) + .maybe_child(error.read().clone().map(|message| { + label() + .text(message) + .font_size(11.) + .max_lines(2) + .width(Size::fill()) + .padding(Gaps::new(0., 14., 10., 14.)) + .color(colors::code_error()) + .into_element() + })) + .into_element() +} diff --git a/packages/oneclient_app/src/view/mod.rs b/packages/oneclient_app/src/view/mod.rs index 6714e422..e063a4c9 100644 --- a/packages/oneclient_app/src/view/mod.rs +++ b/packages/oneclient_app/src/view/mod.rs @@ -2,6 +2,7 @@ mod not_found; mod startup; pub mod app; +pub mod console; pub mod onboarding; pub use not_found::NotFound; diff --git a/packages/oneclient_cluster/src/logs/manage.rs b/packages/oneclient_cluster/src/logs/manage.rs index 9648f25f..51bb5f84 100644 --- a/packages/oneclient_cluster/src/logs/manage.rs +++ b/packages/oneclient_cluster/src/logs/manage.rs @@ -9,8 +9,14 @@ use oneclient_common::paths; use super::parse::parse_level; use super::{LogFileInfo, LogKind, LogLevel, LogLine, LogsError, ReadOptions}; +/// Everything reachable from here lives under a cluster. +/// +/// The launcher's own log directory used to be allowed too, back when this +/// module listed launcher logs alongside the game's. It no longer does — those +/// belong to the live console — so reading, deleting or uploading them is not +/// something a cluster page should be able to reach. pub(super) fn ensure_allowed(path: &Path) -> ClusterResult { - polyio::ensure_under(path, [paths::logs_dir()?, paths::clusters_dir()?])? + polyio::ensure_under(path, [paths::clusters_dir()?])? .ok_or_else(|| LogsError::InvalidName(path.display().to_string()).into()) } @@ -56,6 +62,8 @@ fn collect_dir( } } +/// Everything the game wrote for this cluster: its own logs, its crash reports, +/// and the launcher's capture of the process' stdout. #[tracing::instrument(level = "debug", skip(cluster), fields(cluster_id = cluster.id))] pub fn list_cluster_logs(cluster: &Cluster) -> ClusterResult> { let mut out = Vec::new(); @@ -85,15 +93,6 @@ pub fn list_cluster_logs(cluster: &Cluster) -> ClusterResult> { &mut out, ); - if let Ok(logs_dir) = paths::logs_dir() { - collect_dir( - &logs_dir, - LogKind::Launcher, - |name| name.ends_with(".log") || name.ends_with(".log.gz"), - &mut out, - ); - } - out.sort_by_key(|info| std::cmp::Reverse(info.modified)); Ok(out) } diff --git a/packages/oneclient_cluster/src/logs/mod.rs b/packages/oneclient_cluster/src/logs/mod.rs index 135bf75e..278c9f15 100644 --- a/packages/oneclient_cluster/src/logs/mod.rs +++ b/packages/oneclient_cluster/src/logs/mod.rs @@ -12,15 +12,26 @@ pub use manage::{cluster_output_log, delete_log_at, list_cluster_logs, read_log_ pub use mclogs::upload_log_at; pub use parse::parse_level; +/// What a listed file is. +/// +/// There is no launcher variant: the launcher's own logs are not a cluster's +/// business, and live in the log console instead. #[derive(Clone, Copy, Debug, PartialEq, Eq, Hash)] pub enum LogKind { Game { cluster_id: i64 }, - Launcher, Minecraft, CrashReport, Other, } +impl LogKind { + /// Whether this is a crash report, which the logs page lists separately + /// from the run-of-the-mill output. + pub fn is_crash_report(self) -> bool { + matches!(self, Self::CrashReport) + } +} + #[derive(Clone, Debug, PartialEq)] pub struct LogFileInfo { pub name: String, diff --git a/packages/oneclient_core/src/logger.rs b/packages/oneclient_core/src/logger.rs index 3d8dcbee..584702e6 100644 --- a/packages/oneclient_core/src/logger.rs +++ b/packages/oneclient_core/src/logger.rs @@ -1,24 +1,161 @@ use std::io; +use std::sync::OnceLock; -use tracing_subscriber::EnvFilter; +use parking_lot::Mutex; use tracing_subscriber::layer::SubscriberExt; +use tracing_subscriber::registry::Registry; use tracing_subscriber::util::SubscriberInitExt; +use tracing_subscriber::{EnvFilter, reload}; use crate::LauncherResult; -const DEFAULT_DEBUG_FILTER: &str = "oneclient_app=debug,oneclient_core=debug,oneclient_db=debug,polyio=debug,reqwest=debug,sqlx=debug"; -const DEFAULT_FILTER: &str = "oneclient_app=info,oneclient_core=info,oneclient_db=info,polyio=info"; +pub mod console; + +/// The launcher's own crates. These are the ones anyone reading a log actually +/// wants to hear from, so they get an explicit directive instead of falling +/// back to the base level. +const APP_TARGETS: &[&str] = &[ + "oneclient_app", + "oneclient_auth", + "oneclient_cluster", + "oneclient_common", + "oneclient_content", + "oneclient_core", + "oneclient_db", + "oneclient_discord", + "oneclient_events", + "oneclient_java", + "oneclient_mc", + "oneclient_net", + "oneclient_polyplus", + "polyio", +]; + +/// Dependencies that talk on every request, query, redraw or DNS lookup. +/// +/// The release base level already covers them, but the debug filter raises the +/// base to `info` so that an unfamiliar crate misbehaving still shows up — and +/// that would let this lot back in. A log drowned in `hyper` connection +/// bookkeeping helps nobody, so they are pinned regardless of the base. +const NOISY_TARGETS: &[&str] = &[ + "calloop", + "freya_core", + "freya_winit", + "h2", + "hickory_proto", + "hickory_resolver", + "html5ever", + "hyper", + "hyper_util", + "mio", + "quinn", + "reqwest", + "rustls", + "smithay_client_toolkit", + // Only `sqlx::query`: `sqlx` proper reports pool and migration problems we + // do want, it is the statement-per-line log that is unreadable. + "sqlx::query", + "tokio_util", + "tower", + "want", + "winit", + "zbus", +]; + +/// Directives for a normal run: our crates at `info`, everything else silent +/// unless it is a warning. +pub fn default_directives() -> String { + directives("info", "warn") +} + +/// Directives for "Log Debug Info": our crates at `debug`, and a raised base so +/// an unlisted dependency's `info` still reaches the log. +pub fn debug_directives() -> String { + directives("debug", "info") +} + +fn directives(app_level: &str, base_level: &str) -> String { + let mut out = String::from(base_level); + for target in NOISY_TARGETS { + out.push_str(&format!(",{target}=warn")); + } + for target in APP_TARGETS { + out.push_str(&format!(",{target}={app_level}")); + } + out +} + +/// The filter layer sits directly on the [`Registry`], so that is the subscriber +/// type the reload handle is parameterised over. +type FilterHandle = reload::Handle; + +static FILTER: OnceLock = OnceLock::new(); +static ACTIVE_DIRECTIVES: Mutex = Mutex::new(String::new()); + +#[derive(Debug, thiserror::Error)] +pub enum FilterError { + #[error("invalid log filter directives: {0}")] + Invalid(String), + + #[error("the logger has not been initialized")] + NotInitialized, +} + +/// The directives currently in force, for anything that wants to show them. +pub fn active_directives() -> String { + ACTIVE_DIRECTIVES.lock().clone() +} + +/// Swap the active filter without restarting the launcher. +/// +/// This is what makes the live console worth having: a developer can widen the +/// filter, watch the noise, and narrow it again in the same session. A string +/// that fails to parse leaves the previous filter in place rather than blanking +/// the log. +pub fn set_filter(directives: &str) -> Result<(), FilterError> { + let filter = + EnvFilter::try_new(directives).map_err(|err| FilterError::Invalid(err.to_string()))?; + + FILTER + .get() + .ok_or(FilterError::NotInitialized)? + .reload(filter) + .map_err(|err| FilterError::Invalid(err.to_string()))?; + + *ACTIVE_DIRECTIVES.lock() = directives.to_string(); + tracing::info!(%directives, "log filter reloaded"); + + Ok(()) +} pub fn init_debug() -> LauncherResult<()> { - init_filtered(|| EnvFilter::new(DEFAULT_DEBUG_FILTER)) + init_filtered(debug_directives) } pub fn init() -> LauncherResult<()> { - init_filtered(|| EnvFilter::new(DEFAULT_FILTER)) + init_filtered(default_directives) } -pub fn init_filtered(filter: impl FnOnce() -> EnvFilter) -> LauncherResult<()> { - let filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| filter()); +pub fn init_filtered(filter: impl FnOnce() -> String) -> LauncherResult<()> { + // `RUST_LOG` wins outright rather than being merged in: someone who set it + // asked for exactly those directives, and appending ours would quietly + // override the targets they care about. + let directives = std::env::var(EnvFilter::DEFAULT_ENV) + .ok() + .filter(|value| !value.trim().is_empty()) + .unwrap_or_else(filter); + + let env_filter = EnvFilter::try_new(&directives).unwrap_or_else(|_| { + eprintln!( + "ignoring unparseable {} filter: {directives}", + EnvFilter::DEFAULT_ENV + ); + EnvFilter::new(default_directives()) + }); + + let (filter, handle) = reload::Layer::new(env_filter); + let _ = FILTER.set(handle); + *ACTIVE_DIRECTIVES.lock() = directives; let stdout_layer = tracing_subscriber::fmt::layer().with_writer(io::stdout); @@ -29,6 +166,7 @@ pub fn init_filtered(filter: impl FnOnce() -> EnvFilter) -> LauncherResult<()> { tracing_subscriber::registry() .with(filter) .with(stdout_layer) + .with(console::layer()) .with(sentry_layer) .init(); } @@ -53,6 +191,7 @@ pub fn init_filtered(filter: impl FnOnce() -> EnvFilter) -> LauncherResult<()> { .with(filter) .with(stdout_layer) .with(file_layer) + .with(console::layer()) .with(sentry_layer) .init(); diff --git a/packages/oneclient_core/src/logger/console.rs b/packages/oneclient_core/src/logger/console.rs new file mode 100644 index 00000000..72b6c75e --- /dev/null +++ b/packages/oneclient_core/src/logger/console.rs @@ -0,0 +1,142 @@ +//! The live launcher log console. +//! +//! A [`Layer`] that hands formatted lines to whoever is watching them, and +//! nothing at all when nobody is. The gate is the broadcast channel's own +//! receiver count rather than a flag we maintain: a receiver that goes away +//! because its window closed decrements it on drop, so there is no way to leave +//! capture switched on by accident. + +use std::sync::{Arc, OnceLock}; + +use tokio::sync::broadcast; +use tracing::field::{Field, Visit}; +use tracing::{Event, Level, Subscriber}; +use tracing_subscriber::Layer; +use tracing_subscriber::layer::Context; + +/// How many lines the channel holds for a console that is slow to drain. +/// +/// A console that falls further behind than this loses the oldest lines and is +/// told so, which beats blocking the thread that emitted the log. +const CAPACITY: usize = 4096; + +static CHANNEL: OnceLock> = OnceLock::new(); + +/// One captured event. +#[derive(Clone, Debug)] +pub struct ConsoleLine { + pub level: Level, + /// Pre-formatted as `[HH:MM:SS.mmm] [target/LEVEL]: message`, which is the + /// shape the log viewer already parses for Minecraft logs, so launcher + /// lines get the same colouring for free. + pub text: Arc, +} + +/// A live console. Capture runs for exactly as long as this is alive. +pub struct ConsoleSubscription(broadcast::Receiver); + +impl ConsoleSubscription { + pub async fn recv(&mut self) -> Result { + self.0.recv().await + } +} + +/// Start watching the launcher's logs. +/// +/// Nothing is buffered before this call, so the console opens empty and fills +/// from the moment it is shown. +pub fn subscribe() -> ConsoleSubscription { + ConsoleSubscription(channel().subscribe()) +} + +/// Whether anything is listening. +/// +/// Two atomic loads and a branch is the entire cost of the console layer while +/// no console window is open: nothing is formatted, nothing is allocated, and +/// nothing is buffered. Before a console has ever been opened the channel does +/// not even exist, so it is one load. +pub fn is_capturing() -> bool { + CHANNEL.get().is_some_and(|tx| tx.receiver_count() > 0) +} + +pub(super) fn layer() -> impl Layer { + ConsoleLayer +} + +fn channel() -> &'static broadcast::Sender { + CHANNEL.get_or_init(|| broadcast::channel(CAPACITY).0) +} + +struct ConsoleLayer; + +impl Layer for ConsoleLayer { + fn on_event(&self, event: &Event<'_>, _ctx: Context<'_, S>) { + // Gating here rather than in `Layer::enabled`: that one is ANDed into + // the whole subscriber's decision, so returning `false` from it would + // silence stdout and the log file too whenever the console is shut. + if !is_capturing() { + return; + } + + let meta = event.metadata(); + let mut visitor = LineVisitor::default(); + event.record(&mut visitor); + + let prefix = format!( + "[{}] [{}/{}]: ", + chrono::Local::now().format("%H:%M:%S%.3f"), + meta.target(), + meta.level().as_str(), + ); + + let level = *meta.level(); + let tx = channel(); + + // A message with embedded newlines — a panic backtrace, say — is sent + // line by line so the viewer can scroll and select it like any other. + // Only the first carries the prefix; the rest read as continuations. + let mut body = visitor.message; + body.push_str(&visitor.fields); + + let mut rest = body.lines(); + let first = rest.next().unwrap_or_default(); + let _ = tx.send(ConsoleLine { + level, + text: format!("{prefix}{first}").into(), + }); + + for line in rest { + let _ = tx.send(ConsoleLine { + level, + text: line.into(), + }); + } + } +} + +/// Pulls the `message` field out of an event and renders the rest as +/// `key=value`, matching what the `fmt` layer writes to stdout. +#[derive(Default)] +struct LineVisitor { + message: String, + fields: String, +} + +impl Visit for LineVisitor { + fn record_str(&mut self, field: &Field, value: &str) { + if field.name() == "message" { + self.message.push_str(value); + } else { + self.fields.push_str(&format!(" {}={value}", field.name())); + } + } + + fn record_debug(&mut self, field: &Field, value: &dyn std::fmt::Debug) { + if field.name() == "message" { + self.message.push_str(&format!("{value:?}")); + } else { + self.fields + .push_str(&format!(" {}={value:?}", field.name())); + } + } +}