fix: harden application log viewer

Add an Application Logs window backed by a bounded persistent main log file. The viewer loads history from lanspread.log, subscribes to live INFO/WARN/ERROR log events, supports filtering/copy/pause controls, and keeps the menu/window routing separate from the unpack log viewer. The backend sink now owns serialized access to the log file. History reads and append-time trimming use the same sink lock, so opening the logs window cannot race with a concurrent write and rewrite away a freshly appended line. The sink also keeps a persistent file handle instead of reopening the file for each captured event. Live log events carry sink-local sequence ids. The frontend uses the history watermark plus returned history line counts to suppress live events that were already included in the history response, while preserving buffered rows that were trimmed out of the history file. Auto-scroll now follows the last visible row identity, so it continues following after the in-memory cap keeps the row count stable. No timestamp code change was needed. On the Linux dev host, a temporary probe showed time::OffsetDateTime::now_local() returning +02:00 while UTC was +00:00, matching the host CEST offset. Test Plan: - just fmt - just frontend-test - just test - just clippy - just build - git diff --cached --check - temporary Linux probe of OffsetDateTime::now_local() showed local +02:00 Refs: none
2026-06-07 18:59:05 +02:00
parent d63d4b9c2f
commit 9d14e63613
12 changed files with 1336 additions and 328 deletions
@@ -31,11 +31,14 @@ serde = { workspace = true }
 serde_json = { workspace = true }
 tauri = { workspace = true }
 tauri-plugin-dialog = { workspace = true }
-tauri-plugin-log = { workspace = true }
 tauri-plugin-shell = { workspace = true }
 tauri-plugin-store = { workspace = true }
+time = { workspace = true }
 tokio = { workspace = true }
 tokio-util = { workspace = true }
+tracing = { workspace = true }
+tracing-log = { workspace = true }
+tracing-subscriber = { workspace = true }
 walkdir = { workspace = true }

 [build-dependencies]
@@ -0,0 +1,11 @@
+{
+  "$schema": "../gen/schemas/desktop-schema.json",
+  "identifier": "main-logs",
+  "description": "Capability for the main-logs window",
+  "windows": [
+    "main-logs"
+  ],
+  "permissions": [
+    "core:default"
+  ]
+}
@@ -1,8 +1,10 @@
 use std::{
    collections::{HashMap, HashSet},
+    fs::{self, OpenOptions},
+    io::{self, Read as _, Seek as _, SeekFrom, Write as _},
    net::SocketAddr,
    path::{Component, Path, PathBuf},
-    sync::{Arc, OnceLock},
+    sync::{Arc, Mutex, OnceLock},
    time::{Duration, SystemTime, UNIX_EPOCH},
 };

@@ -28,6 +30,12 @@ use tokio::sync::{
    RwLock,
    mpsc::{UnboundedReceiver, UnboundedSender},
 };
+use tracing::{Event, Level, Metadata, Subscriber, field::Visit};
+use tracing_subscriber::{
+    layer::{Context, Layer},
+    prelude::*,
+    registry::LookupSpan,
+};

 // Learn more about Tauri commands at https://tauri.app/develop/calling-rust/

@@ -79,6 +87,7 @@ struct LanSpreadState {
    catalog: Arc<RwLock<GameCatalog>>,
    unpack_logs: Arc<RwLock<Vec<UnpackLogEntry>>>,
    state_dir: OnceLock<PathBuf>,
+    main_log_sink: OnceLock<MainLogSink>,
    active_outbound_transfers: OutboundTransfers,
    outbound_transfer_emit: Arc<RwLock<OutboundTransferEmitState>>,
 }
@@ -132,12 +141,29 @@ struct UnpackLogEntry {
    success: bool,
 }

+#[derive(Clone, Debug, serde::Serialize)]
+struct MainLogLinePayload {
+    line: String,
+    level: String,
+    sequence: Option<u64>,
+}
+
+#[derive(Clone, Debug, serde::Serialize)]
+#[serde(rename_all = "camelCase")]
+struct MainLogHistoryPayload {
+    contents: String,
+    last_sequence: u64,
+}
+
 struct SidecarUnpacker {
    app_handle: AppHandle,
 }

 const MAX_UNPACK_LOGS: usize = 20;
 const UNPACK_LOGS_FILE_NAME: &str = "unpack-logs.json";
+const MAIN_LOG_FILE_NAME: &str = "lanspread.log";
+const MAX_MAIN_LOG_BYTES: u64 = 2 * 1024 * 1024;
+const MAIN_LOG_TRIM_SLACK_BYTES: u64 = 64 * 1024;

 impl Unpacker for SidecarUnpacker {
    fn unpack<'a>(&'a self, archive: &'a Path, dest: &'a Path) -> UnpackFuture<'a> {
@@ -156,6 +182,32 @@ async fn get_unpack_logs(
    Ok(state.inner().unpack_logs.read().await.clone())
 }

+#[tauri::command]
+async fn get_main_logs(
+    app_handle: tauri::AppHandle,
+    state: tauri::State<'_, LanSpreadState>,
+) -> tauri::Result<MainLogHistoryPayload> {
+    if let Some(sink) = state.inner().main_log_sink.get() {
+        return Ok(sink.read_history()?);
+    }
+
+    let state_dir = app_handle.path().app_data_dir()?;
+    fs::create_dir_all(&state_dir)?;
+    let path = main_log_path(&state_dir);
+
+    match read_main_log_file_to_limit(&path, MAX_MAIN_LOG_BYTES) {
+        Ok(contents) => Ok(MainLogHistoryPayload {
+            contents,
+            last_sequence: 0,
+        }),
+        Err(err) if err.kind() == io::ErrorKind::NotFound => Ok(MainLogHistoryPayload {
+            contents: String::new(),
+            last_sequence: 0,
+        }),
+        Err(err) => Err(err.into()),
+    }
+}
+
 #[cfg_attr(not(target_os = "windows"), allow(dead_code))]
 const GAME_SETUP_SCRIPT: &str = "game_setup.cmd";
 #[cfg_attr(not(target_os = "windows"), allow(dead_code))]
@@ -1349,6 +1401,362 @@ fn unpack_logs_path(state_dir: &Path) -> PathBuf {
    state_dir.join(UNPACK_LOGS_FILE_NAME)
 }

+fn main_log_path(state_dir: &Path) -> PathBuf {
+    state_dir.join(MAIN_LOG_FILE_NAME)
+}
+
+#[cfg(test)]
+fn trim_main_log_file_to_limit(path: &Path, max_bytes: u64) -> io::Result<()> {
+    let mut file = match OpenOptions::new().read(true).write(true).open(path) {
+        Ok(file) => file,
+        Err(err) if err.kind() == io::ErrorKind::NotFound => return Ok(()),
+        Err(err) => return Err(err),
+    };
+
+    trim_main_log_file_to_limit_with_file(&mut file, max_bytes)
+}
+
+fn trim_main_log_file_to_limit_with_file(file: &mut fs::File, max_bytes: u64) -> io::Result<()> {
+    let metadata = file.metadata()?;
+
+    if metadata.len() <= max_bytes {
+        file.seek(SeekFrom::End(0))?;
+        return Ok(());
+    }
+
+    let tail = if max_bytes == 0 {
+        String::new()
+    } else {
+        file.seek(SeekFrom::Start(metadata.len() - max_bytes))?;
+
+        let mut bytes = Vec::with_capacity(usize::try_from(max_bytes).unwrap_or(usize::MAX));
+        file.read_to_end(&mut bytes)?;
+        valid_utf8_tail(bytes)
+    };
+
+    file.set_len(0)?;
+    file.seek(SeekFrom::Start(0))?;
+    file.write_all(tail.as_bytes())?;
+    file.seek(SeekFrom::End(0))?;
+    Ok(())
+}
+
+fn read_main_log_file_to_limit(path: &Path, max_bytes: u64) -> io::Result<String> {
+    let mut file = fs::File::open(path)?;
+    read_main_log_file_to_limit_with_file(&mut file, max_bytes)
+}
+
+fn read_main_log_file_to_limit_with_file(
+    file: &mut fs::File,
+    max_bytes: u64,
+) -> io::Result<String> {
+    let metadata = file.metadata()?;
+    if metadata.len() == 0 || max_bytes == 0 {
+        file.seek(SeekFrom::End(0))?;
+        return Ok(String::new());
+    }
+
+    let start = metadata.len().saturating_sub(max_bytes);
+    file.seek(SeekFrom::Start(start))?;
+
+    let capacity = usize::try_from(metadata.len() - start).unwrap_or(usize::MAX);
+    let mut bytes = Vec::with_capacity(capacity);
+    file.read_to_end(&mut bytes)?;
+    file.seek(SeekFrom::End(0))?;
+
+    if start == 0 {
+        Ok(String::from_utf8_lossy(&bytes).into_owned())
+    } else {
+        Ok(valid_utf8_tail(bytes))
+    }
+}
+
+fn valid_utf8_tail(bytes: Vec<u8>) -> String {
+    for offset in 0..bytes.len().min(4) {
+        if let Ok(tail) = std::str::from_utf8(&bytes[offset..]) {
+            return tail.to_string();
+        }
+    }
+
+    String::from_utf8_lossy(&bytes).into_owned()
+}
+
+#[derive(Clone)]
+struct MainLogSink {
+    app_handle: AppHandle,
+    path: PathBuf,
+    file_state: Arc<Mutex<MainLogFileState>>,
+}
+
+#[derive(Default)]
+struct MainLogFileState {
+    file: Option<fs::File>,
+    last_sequence: u64,
+}
+
+impl MainLogSink {
+    fn new(app_handle: AppHandle, path: PathBuf) -> Self {
+        Self {
+            app_handle,
+            path,
+            file_state: Arc::new(Mutex::new(MainLogFileState::default())),
+        }
+    }
+
+    fn write_line(&self, line: String, level: Level) {
+        write_main_log_stdout(&line);
+        let sequence = self.append_file_line(&line);
+
+        let _ = self.app_handle.emit(
+            "main-log-line",
+            MainLogLinePayload {
+                line,
+                level: level.as_str().to_string(),
+                sequence,
+            },
+        );
+    }
+
+    fn read_history(&self) -> io::Result<MainLogHistoryPayload> {
+        let mut file_state = self
+            .file_state
+            .lock()
+            .map_err(|_| io::Error::other("main log file lock poisoned"))?;
+
+        if file_state.file.is_none() && !self.path.exists() {
+            return Ok(MainLogHistoryPayload {
+                contents: String::new(),
+                last_sequence: file_state.last_sequence,
+            });
+        }
+
+        let contents = {
+            let file = self.cached_file(&mut file_state.file)?;
+            trim_main_log_file_to_limit_with_file(file, MAX_MAIN_LOG_BYTES)?;
+            read_main_log_file_to_limit_with_file(file, MAX_MAIN_LOG_BYTES)?
+        };
+
+        Ok(MainLogHistoryPayload {
+            contents,
+            last_sequence: file_state.last_sequence,
+        })
+    }
+
+    fn append_file_line(&self, line: &str) -> Option<u64> {
+        let Ok(mut file_state) = self.file_state.lock() else {
+            return None;
+        };
+
+        let write_result = self.cached_file(&mut file_state.file).and_then(|file| {
+            file.seek(SeekFrom::End(0))
+                .and_then(|_| writeln!(file, "{line}"))
+        });
+
+        if write_result.is_err() {
+            file_state.file = None;
+            return None;
+        }
+
+        file_state.last_sequence = file_state.last_sequence.saturating_add(1);
+        let sequence = file_state.last_sequence;
+
+        let should_trim = file_state.file.as_ref().is_some_and(|file| {
+            file.metadata().is_ok_and(|metadata| {
+                metadata.len() > MAX_MAIN_LOG_BYTES.saturating_add(MAIN_LOG_TRIM_SLACK_BYTES)
+            })
+        });
+
+        if should_trim && let Some(file) = file_state.file.as_mut() {
+            let _ = trim_main_log_file_to_limit_with_file(file, MAX_MAIN_LOG_BYTES);
+        }
+
+        Some(sequence)
+    }
+
+    fn cached_file<'a>(&self, file: &'a mut Option<fs::File>) -> io::Result<&'a mut fs::File> {
+        if file.is_none() {
+            *file = Some(open_main_log_file(&self.path)?);
+        }
+
+        file.as_mut()
+            .ok_or_else(|| io::Error::other("main log file was not opened"))
+    }
+}
+
+fn open_main_log_file(path: &Path) -> io::Result<fs::File> {
+    if let Some(parent) = path.parent() {
+        fs::create_dir_all(parent)?;
+    }
+
+    OpenOptions::new()
+        .create(true)
+        .truncate(false)
+        .read(true)
+        .write(true)
+        .open(path)
+}
+
+struct MainLogLayer {
+    sink: MainLogSink,
+}
+
+impl MainLogLayer {
+    fn new(sink: MainLogSink) -> Self {
+        Self { sink }
+    }
+}
+
+impl<S> Layer<S> for MainLogLayer
+where
+    S: Subscriber + for<'span> LookupSpan<'span>,
+{
+    fn enabled(&self, metadata: &Metadata<'_>, _ctx: Context<'_, S>) -> bool {
+        should_capture_main_log_metadata(metadata)
+    }
+
+    fn on_event(&self, event: &Event<'_>, _ctx: Context<'_, S>) {
+        let metadata = event.metadata();
+        if !should_capture_main_log_metadata(metadata) {
+            return;
+        }
+
+        let mut visitor = MainLogFieldVisitor::default();
+        event.record(&mut visitor);
+        let target = visitor
+            .log_target
+            .clone()
+            .unwrap_or_else(|| metadata.target().to_string());
+        let message = visitor.into_message();
+        let (date, time) = current_main_log_timestamp();
+        let line =
+            format_main_log_line_parts(&date, &time, &target, metadata.level().as_str(), &message);
+
+        self.sink.write_line(line, *metadata.level());
+    }
+}
+
+#[derive(Default)]
+struct MainLogFieldVisitor {
+    message: Option<String>,
+    log_target: Option<String>,
+    fields: Vec<String>,
+}
+
+impl MainLogFieldVisitor {
+    fn record_value(&mut self, field_name: &str, value: String) {
+        match field_name {
+            "message" => self.message = Some(value),
+            "log.target" => self.log_target = Some(value),
+            "log.module_path" | "log.file" | "log.line" => {}
+            _ => self.fields.push(format!("{field_name}={value}")),
+        }
+    }
+
+    fn into_message(self) -> String {
+        let mut parts = Vec::new();
+        if let Some(message) = self.message
+            && !message.is_empty()
+        {
+            parts.push(message);
+        }
+        parts.extend(self.fields);
+
+        if parts.is_empty() {
+            String::from("(no message)")
+        } else {
+            normalize_main_log_message(&parts.join(" "))
+        }
+    }
+}
+
+impl Visit for MainLogFieldVisitor {
+    fn record_bool(&mut self, field: &tracing::field::Field, value: bool) {
+        self.record_value(field.name(), value.to_string());
+    }
+
+    fn record_i64(&mut self, field: &tracing::field::Field, value: i64) {
+        self.record_value(field.name(), value.to_string());
+    }
+
+    fn record_u64(&mut self, field: &tracing::field::Field, value: u64) {
+        self.record_value(field.name(), value.to_string());
+    }
+
+    fn record_str(&mut self, field: &tracing::field::Field, value: &str) {
+        self.record_value(field.name(), value.to_string());
+    }
+
+    fn record_debug(&mut self, field: &tracing::field::Field, value: &dyn std::fmt::Debug) {
+        self.record_value(field.name(), format!("{value:?}"));
+    }
+}
+
+fn should_capture_main_log_metadata(metadata: &Metadata<'_>) -> bool {
+    if metadata.target().starts_with("mdns_sd::service_daemon") {
+        return false;
+    }
+
+    matches!(*metadata.level(), Level::ERROR | Level::WARN | Level::INFO)
+}
+
+fn current_main_log_timestamp() -> (String, String) {
+    let now = time::OffsetDateTime::now_local().unwrap_or_else(|_| time::OffsetDateTime::now_utc());
+    let date = now.date();
+    let clock = now.time();
+
+    (
+        format!(
+            "{:04}-{:02}-{:02}",
+            date.year(),
+            u8::from(date.month()),
+            date.day()
+        ),
+        format!(
+            "{:02}:{:02}:{:02}",
+            clock.hour(),
+            clock.minute(),
+            clock.second()
+        ),
+    )
+}
+
+fn format_main_log_line_parts(
+    date: &str,
+    time: &str,
+    target: &str,
+    level: &str,
+    message: &str,
+) -> String {
+    format!(
+        "[{date}][{time}][{}][{level}] {}",
+        normalize_main_log_target(target),
+        normalize_main_log_message(message)
+    )
+}
+
+fn normalize_main_log_target(target: &str) -> String {
+    target.replace(['\r', '\n'], " ")
+}
+
+fn normalize_main_log_message(message: &str) -> String {
+    message.replace('\r', "\\r").replace('\n', "\\n")
+}
+
+fn write_main_log_stdout(line: &str) {
+    let stdout = std::io::stdout();
+    let mut stdout = stdout.lock();
+    let _ = writeln!(stdout, "{line}");
+}
+
+fn init_main_logging(sink: MainLogSink) -> Result<(), Box<dyn std::error::Error>> {
+    let subscriber = tracing_subscriber::registry().with(MainLogLayer::new(sink));
+    tracing::subscriber::set_global_default(subscriber)?;
+    tracing_log::LogTracer::builder()
+        .with_max_level(log::LevelFilter::Info)
+        .init()?;
+    Ok(())
+}
+
 fn load_unpack_logs(state_dir: &Path) -> Vec<UnpackLogEntry> {
    let path = unpack_logs_path(state_dir);
    let contents = match std::fs::read_to_string(&path) {
@@ -1918,6 +2326,46 @@ mod tests {
        let _ = std::fs::remove_dir_all(root);
    }

+    #[test]
+    fn main_log_line_format_is_stable_and_single_line() {
+        let line = format_main_log_line_parts(
+            "2026-06-07",
+            "12:34:56",
+            "lanspread\napp",
+            "WARN",
+            "first line\nsecond line",
+        );
+
+        assert_eq!(
+            line,
+            "[2026-06-07][12:34:56][lanspread app][WARN] first line\\nsecond line"
+        );
+    }
+
+    #[test]
+    fn main_log_trim_keeps_utf8_tail_at_char_boundary() {
+        let root = std::env::temp_dir().join(format!(
+            "lanspread-main-log-test-{}",
+            SystemTime::now()
+                .duration_since(UNIX_EPOCH)
+                .expect("clock should be after epoch")
+                .as_nanos()
+        ));
+        std::fs::create_dir_all(&root).expect("test state dir should be created");
+        let path = main_log_path(&root);
+        std::fs::write(&path, format!("{}{}", "a".repeat(11), "é".repeat(20)))
+            .expect("main log should be written");
+
+        trim_main_log_file_to_limit(&path, 21).expect("main log should trim");
+
+        let trimmed = std::fs::read_to_string(&path).expect("trimmed log should remain utf-8");
+        assert!(trimmed.as_bytes().len() <= 21);
+        assert!(trimmed.starts_with('é'));
+        assert!(trimmed.ends_with('é'));
+
+        let _ = std::fs::remove_dir_all(root);
+    }
+
    #[test]
    fn active_operation_reconciliation_replaces_stale_ui_history() {
        let mut active_operations = HashMap::from([
@@ -2220,21 +2668,12 @@ mod tests {
 #[allow(clippy::missing_panics_doc)]
 #[cfg_attr(mobile, tauri::mobile_entry_point)]
 pub fn run() {
-    let tauri_logger_builder = tauri_plugin_log::Builder::new()
-        .clear_targets()
-        .target(tauri_plugin_log::Target::new(
-            tauri_plugin_log::TargetKind::Stdout,
-        ))
-        .level(log::LevelFilter::Info)
-        .level_for("mdns_sd::service_daemon", log::LevelFilter::Off);
-
    // channel to receive events from the peer
    let (tx_peer_event, rx_peer_event) = tokio::sync::mpsc::unbounded_channel::<PeerEvent>();

    tauri::Builder::default()
        .plugin(tauri_plugin_store::Builder::new().build())
        .plugin(tauri_plugin_dialog::init())
-        .plugin(tauri_logger_builder.build())
        .plugin(tauri_plugin_shell::init())
        .invoke_handler(tauri::generate_handler![
            request_games,
@@ -2250,14 +2689,20 @@ pub fn run() {
            open_game_files,
            get_peer_count,
            get_game_thumbnail,
-            get_unpack_logs
+            get_unpack_logs,
+            get_main_logs
        ])
        .manage(LanSpreadState::default())
        .manage(PeerEventTx(tx_peer_event))
        .setup(move |app| {
            let state_dir = app.path().app_data_dir()?;
            std::fs::create_dir_all(&state_dir)?;
+            let main_log_sink = MainLogSink::new(app.handle().clone(), main_log_path(&state_dir));
            let state = app.state::<LanSpreadState>();
+            if state.main_log_sink.set(main_log_sink.clone()).is_err() {
+                log::warn!("main log sink was already initialized");
+            }
+            init_main_logging(main_log_sink)?;
            let unpack_logs = load_unpack_logs(&state_dir);
            tauri::async_runtime::block_on(async {
                *state.unpack_logs.write().await = unpack_logs;