diff --git a/docs/index.md b/docs/index.md index 35dc3a68d..81d1b6317 100644 --- a/docs/index.md +++ b/docs/index.md @@ -15,6 +15,7 @@ - [交接总览](linux-egui-handoff/README.md):阅读顺序、责任与复用起点。 - [01 Core 合同](linux-egui-handoff/01-core-contract.md)、[02 缺口登记](linux-egui-handoff/02-gap-register.md)(L01–L12)、[03 热键与窗口](linux-egui-handoff/03-hotkeys-and-windows.md)、[04 页面与领域](linux-egui-handoff/04-ui-domains.md)、[05 原生宿主与数据](linux-egui-handoff/05-native-host-and-data.md)、[06 事件与会话](linux-egui-handoff/06-events-and-sessions.md)、[07 验收](linux-egui-handoff/07-acceptance.md)。 +- [Linux egui 日志约定](linux-egui-logging.md):级别语义、`OPENLESS_LOG` 开关、轮转策略与不记录的内容。 - [Linux 已知缺口](linux-egui-known-gaps.md):当前仍未闭环的行为与复现路径(如 G01 纠错卡)。 ## 接口契约 diff --git a/docs/linux-egui-logging.md b/docs/linux-egui-logging.md new file mode 100644 index 000000000..ec38ec237 --- /dev/null +++ b/docs/linux-egui-logging.md @@ -0,0 +1,137 @@ +# Linux egui 日志约定 + +状态:canonical;更新:2026-10-22。适用于 `openless-all/app/linux-egui`,以及被两个前端共用的 `crates/openless-core`。 + +日志是 Linux 用户唯一能交回来的证据:界面出错时他们既没有控制台,也不会跑 gdb。所以这份文件规定的不是文风,而是**「出问题时能不能从日志里读出结论」**。 + +## 1. 落在哪里 + +| 项 | 值 | +|---|---| +| 文件 | `$XDG_DATA_HOME/openless/logs/openless.log`(默认 `~/.local/share/OpenLess/logs/`) | +| 单文件上限 | 2 MiB | +| 历史份数 | `openless.log.1` … `openless.log.3`(合计 ≤ 8 MiB) | +| 轮转时机 | 进程启动时;**只有宿主轮转**,UI 窗口进程不轮转(否则宿主手里的句柄会指向被改名的 inode) | +| 终端 | 同时输出到 stderr,级别与文件一致 | +| 导出 | 设置 → 高级 → 调试 → 「导出错误日志」(`export_error_logs`,原子写) | +| 导出内容 | 当前 `openless.log` **加全部轮转历史**(`.3`→`.2`→`.1`→当前,时间正序),文件头写明版本、系统架构、生效级别与导出时间 | + +两个进程(宿主 `openless`、界面 `openless --ui-client`)写同一个文件,排查「窗口进程怎么没了」时两端记录在同一处。 + +## 2. 级别 + +| 级别 | 用来记什么 | 判据 | +|---|---|---| +| `error` | **失败**。用户可见的能力没做到,或数据可能受损 | 「这条出现时,功能是坏的」 | +| `warn` | 降级但仍然工作:回退到默认设备、重试成功、可选能力缺失 | 「这条出现时,行为与预期不同」 | +| `info` | **状态变化**与低频存活证明(热键注册结果、模型加载、云同步相位、会话开始/结束) | 用户报「它不工作了」时,需要看到「上一次好的是哪一步」 | +| `debug` | 周期仪表:心跳、IPC 往返、逐帧/逐事件细节 | 打开后能让 `info` 的结论落到具体数值 | +| `trace` | 逐条协议/逐样本,只为复现一次具体 bug | 默认关闭,通常只用一次 | + +两条硬规则: + +1. **周期性的东西不许写 `info`。** 每 10 秒一条 = 8640 行/天,轮转后整份日志九成都是它,真正的错误被挤出去。这类日志写 `debug`,`info` 只留状态变化与低频存活证明。 + - 参考实现:`log_pump_heartbeat`(`linux-egui/src/main.rs`)——状态变化立刻记 `info`,否则每 5 分钟一条,其余 `debug`。 +2. **`error` 只写失败,不写进度。** `log::error!("[x] stage=device_id_ok")` 这类 tracer 会让每次启动看起来都像崩了,必须降到 `debug`。 + +## 3. 设置里也能改 + +设置 → 高级 → 调试 → **日志级别**(`info` / `debug` / `trace`): + +- 选完写进 `/logs/level`,**重启 OpenLess 生效**(界面会提示)。 +- 这是宿主本地设置,不进 Core 偏好,因此不上云、不影响 Tauri 与移动端。 +- 环境变量优先于这里的设置:临时排查不该被上一次的界面选择挡住。 + +## 4. 不用重新编译也能改级别 + +```bash +# 全开 +OPENLESS_LOG=debug openless + +# 只把 Core 的依赖图噪声打开 +OPENLESS_LOG=info,openless_core=debug openless + +# 环境变量在 systemd 启动的情况下要写进服务定义 +systemctl --user edit openless +# [Service] +# Environment=OPENLESS_LOG=debug +``` + +`OPENLESS_LOG` 优先,`RUST_LOG` 作为兼容名也认。语法: + +``` +[,=]... +``` + +- 模块前缀按 `::` 边界匹配,**最长匹配优先**(`openless_core::asr=warn` 会盖住 `openless_core=debug`)。 +- 任何无法识别的片段会让整条规则退回默认 `info`:宁可多记,不可静默少记。 +- 默认 `info`。发布版不需要用户改任何东西就能看到状态变化。 + +启动时的第一行会写明生效的过滤与是否轮转过: + +``` +2026-10-22T23:40:12.423+08:00 [INFO] openless_linux_egui::logging: Linux egui logger ready: level=debug rotated=false path=/home/x/.local/share/OpenLess/logs/openless.log +``` + +## 5. 行格式 + +``` +<本地时区 RFC3339> [] [] [] <文件:行> <消息> +``` + +- `target` 一直在(模块路径),定位「哪一层打的」不用猜。 +- 线程名与源码位置只在 `debug` 及以上出现,避免 `info` 行变长。 +- 时间戳是**用户本地时区**。历史版本写 UTC(结尾 `Z`),用户对着自己的操作时间找不到对应行。 + +消息里的固定前缀是约定,用方括号小写,便于 `grep '\[fcitx\]'`: + +| 前缀 | 范围 | +|---|---| +| `[pump]` | 宿主循环存活 | +| `[hotkey]` | 热键注册与分发 | +| `[fcitx]` | fcitx5 addon 通信 | +| `[ui-host]` / `[ui-client]` | 两个进程各自的 IPC 侧 | +| `[dictation]` | 一次听写的生命周期(Core) | +| `[insert-diagnostics]` | 文本注入 | +| `[audio]` / `[audio-cue]` / `[audio-mute]` | 采集与提示音 | +| `[style]` | 风格包 | +| `[remote-input]` | 手机/远程输入 | +| `[capture]` | 截图与选区 | + +## 6. 一次听写在日志里长什么样 + +``` +[dictation] start session_id=… target=Dictation asr=dashscope insert=true translate=false silence_after_ms=None +[audio] capture started backend=pipewire device=… format=F32 rate=48000Hz channels=1 +[transcript] partial emitted session=… ← 仅 debug +[asr] session_id=… provider=dashscope label=… elapsed_ms=1840 chars=42 +[asr-diagnostics] session_id=… asr_chars=42 asr_hash=… corrected_chars=42 … +[polish-diagnostics] session_id=… stage=decision uses_polisher=true … +[insert-diagnostics] session_id=… attempt=1 operation=… chars=42 hash=… +[dictation] session … failed: code=… message=… ← 失败时(warn) +``` + +## 7. 定位一次听写 + +同一次听写里的多行用 `session_id` 串起来(`[dictation]`、`[insert-diagnostics]` 都带)。排查顺序: + +```bash +grep 'session_id=' ~/.local/share/OpenLess/logs/openless.log* +``` + +失败原因现在会同时给出 `code` 与 `message`(见 `mark_dictation_failed`)。历史版本只有 `code`,因此「录音停止 / 转写 / 润色」这一步光看日志分不出来。 + +## 8. 不要记录的东西 + +- 任何凭据:API key、token、password、私钥、keystore 内容。日志会被用户原样贴到 issue 里。 +- 用户听写的正文。需要时可记长度或哈希(`[insert-diagnostics]` 就是这么做的:`chars=` / `hash=`)。 +- 完整 `data_dir` 之外的路径通常没必要;`data_dir` 本身要记,因为「日志写在哪」是第一个问题。 + +`scripts/egui-logging-contract.test.mjs` 会拒绝形如 `api_key=` / `token=` / `password=` 的日志格式化参数,以及 `stage=` 级别的 `error`。 + +## 9. 改动这份约定时 + +- 新增周期日志 → 必须是 `debug`,或带节流。 +- 新增 `info` → 必须能回答「状态变了什么」。 +- 新增 `error` → 必须对应一次真实的失败分支。 +- 跑 `node scripts/egui-logging-contract.test.mjs`。 diff --git a/openless-all/app/crates/openless-core/src/api.rs b/openless-all/app/crates/openless-core/src/api.rs index 480c5002a..3402ab525 100644 --- a/openless-all/app/crates/openless-core/src/api.rs +++ b/openless-all/app/crates/openless-core/src/api.rs @@ -7809,6 +7809,17 @@ impl OpenLessBackend { context }; + // 一次听写的起点。日志从「按下热键」到第一条识别结果之间原本是空白, + // 于是「按了没反应」与「录上了但没识别」在日志里长得一样。 + log::info!( + "[dictation] start session_id={} target={:?} asr={} insert={} translate={} silence_after_ms={:?}", + session_id, + context.output_target, + context.asr.provider_type, + context.insertion.enabled, + context.polish.translation_active, + context.recording.silence_after_ms, + ); if let Err(error) = self .deps .host_actions diff --git a/openless-all/app/crates/openless-core/src/cloud_sync_e2ee/adapter.rs b/openless-all/app/crates/openless-core/src/cloud_sync_e2ee/adapter.rs index f5ce14cf0..ec0167d72 100644 --- a/openless-all/app/crates/openless-core/src/cloud_sync_e2ee/adapter.rs +++ b/openless-all/app/crates/openless-core/src/cloud_sync_e2ee/adapter.rs @@ -43,7 +43,7 @@ pub(crate) fn build( } let origin = origin.origin().ascii_serialization(); let root = data_dir.join("encrypted-sync"); - log::error!( + log::debug!( "[e2ee-adapter] build start data_dir={} root={}", data_dir.display(), root.display() @@ -55,15 +55,15 @@ pub(crate) fn build( ); super::error("local_storage_unavailable") })?; - log::error!("[e2ee-adapter] stage=gate_open"); + log::debug!("[e2ee-adapter] stage=gate_open"); let gate = crate::cloud_sync_e2ee_store::gate::open_for_data_dir(data_dir).map_err(|error| { log::error!("[e2ee-adapter] reopen sync write gate failed: {error:#}"); document_error(error) })?; - log::error!("[e2ee-adapter] stage=device_id"); + log::debug!("[e2ee-adapter] stage=device_id"); let device_id = load_device_id(&root)?; - log::error!( + log::debug!( "[e2ee-adapter] stage=device_id_ok id_len={}", device_id.len() ); @@ -79,7 +79,7 @@ pub(crate) fn build( device_id, credentials.clone(), ); - log::error!("[e2ee-adapter] stage=store_new"); + log::debug!("[e2ee-adapter] stage=store_new"); let credential_store_for_service = credentials.clone(); let store = Arc::new( CoreSyncStore::new( @@ -96,7 +96,7 @@ pub(crate) fn build( document_error(error) })?, ); - log::error!("[e2ee-adapter] stage=store_ok"); + log::debug!("[e2ee-adapter] stage=store_ok"); let service = super::EncryptedSyncService::new( super::SyncServiceConfig { origin, diff --git a/openless-all/app/crates/openless-core/src/dictation_engine.rs b/openless-all/app/crates/openless-core/src/dictation_engine.rs index a121f3efe..3a95c61cb 100644 --- a/openless-all/app/crates/openless-core/src/dictation_engine.rs +++ b/openless-all/app/crates/openless-core/src/dictation_engine.rs @@ -949,7 +949,17 @@ impl DictationEngine for PipelineDictationEngine { } } }; - let asr_ms = Some(asr_started.elapsed().as_millis() as u64); + let asr_elapsed_ms = asr_started.elapsed().as_millis() as u64; + let asr_ms = Some(asr_elapsed_ms); + // 「听写很慢」时要能一句话看出慢在 ASR 还是慢在润色。 + log::info!( + "[asr] session_id={} provider={} label={:?} elapsed_ms={} chars={}", + session_id, + context.asr.provider_type, + asr_call_label, + asr_elapsed_ms, + transcript.text.chars().count(), + ); if session.cancelled.load(Ordering::Acquire) { if !context.recording.archive_successful_recording { discard_ephemeral_archive(archive.as_ref(), &mut has_audio_recording).await; @@ -2195,7 +2205,9 @@ struct TranscriptProgressForwarder { impl TextStreamSink for TranscriptProgressForwarder { fn publish(&self, chunk: TextStreamChunk) -> Result<(), BackendError> { - log::info!( + // 流式转写每来一块就一条;它属于逐事件仪表,走 debug, + // 否则一次长听写就能把 info 层刷满。 + log::debug!( "[transcript] partial emitted session={} offset={} chars={}", self.session_id, chunk.offset, diff --git a/openless-all/app/linux-egui/src/audio.rs b/openless-all/app/linux-egui/src/audio.rs index 5e5d931af..adb75bc7a 100644 --- a/openless-all/app/linux-egui/src/audio.rs +++ b/openless-all/app/linux-egui/src/audio.rs @@ -485,6 +485,11 @@ fn run_audio_thread(args: LinuxAudioThreadArgs) { stream } Err(error) => { + log::error!( + "[audio] no input backend could open a stream (tried {:?}): {}", + audio_backend_order(), + error.message + ); drop(frame_tx); let _ = processor.finish(); let _ = startup.send(Err(error)); @@ -540,6 +545,15 @@ fn try_start_audio_stream( .play() .map_err(|error| classify_audio_error("start input stream", error.to_string()))?; accepting.store(true, std::sync::atomic::Ordering::Release); + // 「录到的全是静音」这类问题,第一个要回答的就是:落到哪个后端、哪只 + // 设备、什么采样格式。以前只有失败时才有日志,成功时什么都看不到。 + log::info!( + "[audio] capture started backend={backend} device={} format={:?} rate={}Hz channels={}", + device, + supported.sample_format(), + supported.sample_rate(), + usize::from(supported.channels()), + ); Ok(stream) }; let initial_error = match device.default_input_config() { diff --git a/openless-all/app/linux-egui/src/i18n.rs b/openless-all/app/linux-egui/src/i18n.rs index 29bc7c752..13ca6fe9e 100644 --- a/openless-all/app/linux-egui/src/i18n.rs +++ b/openless-all/app/linux-egui/src/i18n.rs @@ -1468,6 +1468,7 @@ pub const CATALOG: &[Msg] = &[ Msg { key: "status.channel_saved", text: row("渠道配置已保存", "管道設定已儲存", "Channel configuration saved", "チャネル設定を保存しました", "채널 설정 저장됨") }, Msg { key: "status.secret_cleared", text: row("渠道 Secret 已清除", "管道 Secret 已清除", "Channel Secret cleared", "チャネルの Secret を消去しました", "채널 Secret 지워짐") }, Msg { key: "status.provider_validated", text: row("Provider 验证通过({} ms)", "Provider 驗證通過({} ms)", "Provider validated ({} ms)", "Provider 検証成功({} ms)", "Provider 검증 통과({}ms)") }, + Msg { key: "status.log_level_saved", text: row("日志级别已保存,重启 OpenLess 后生效", "日誌等級已儲存,重新啟動 OpenLess 後生效", "Log level saved; restart OpenLess to apply", "ログレベルを保存しました。OpenLess の再起動で反映されます", "로그 레벨을 저장했습니다. OpenLess를 다시 시작하면 적용됩니다") }, Msg { key: "status.export_log_done", text: row("错误日志已导出", "錯誤日誌已匯出", "Error log exported", "エラーログをエクスポートしました", "오류 로그 내보냄") }, Msg { key: "status.hotkey_handled", text: row("已处理快捷键", "已處理快速鍵", "Hotkey handled", "ホットキーを処理しました", "단축키 처리됨") }, Msg { key: "status.launch_handled", text: row("已处理启动请求", "已處理啟動請求", "Launch request handled", "起動要求を処理しました", "시작 요청 처리됨") }, @@ -3794,6 +3795,20 @@ pub const CATALOG: &[Msg] = &[ "Shift+Insert (xterm / urxvt)", ), }, + Msg { + key: "settings.debug.log_level_label", + text: row("日志级别", "日誌等級", "Log level", "ログレベル", "로그 레벨"), + }, + Msg { + key: "settings.debug.log_level_desc", + text: row( + "debug 记录心跳与 IPC 细节,排查问题时更有用;选择后需重启 OpenLess 生效。", + "debug 記錄心跳與 IPC 細節,排查問題時更有用;選擇後需重新啟動 OpenLess 生效。", + "debug records heartbeats and IPC details, which is what support needs; restart OpenLess to apply.", + "debug はハートビートと IPC の詳細を記録します(調査向け)。OpenLess の再起動で反映されます。", + "debug는 하트비트와 IPC 세부 정보를 기록합니다(문제 해결용). OpenLess를 다시 시작해야 적용됩니다.", + ), + }, Msg { key: "settings.recording.record_audio_for_debug_label", text: row( diff --git a/openless-all/app/linux-egui/src/lib.rs b/openless-all/app/linux-egui/src/lib.rs index d0bdb47e3..765508486 100644 --- a/openless-all/app/linux-egui/src/lib.rs +++ b/openless-all/app/linux-egui/src/lib.rs @@ -95,7 +95,10 @@ pub use local_hotkeys::{ next_local_press_id, plugin_event_hotkey, style_pack_raw, translation_hotkey_event, HotkeyDeduplicator, LocalHotkey, LocalHotkeyEdge, LocalHotkeyEdgeKind, HOTKEY_DEDUPE_WINDOW, }; -pub use logging::{export_error_log, init_file_logger, log_path}; +pub use logging::{ + export_error_log, export_error_logs, init_file_logger, level_name, log_path, read_log_level, + write_log_level, +}; pub use popup::{ force_x11_for, popup_command, read_jsonl, run_popup, write_jsonl, ApplyOutcome as PopupApplyOutcome, CapsulePopupState, CapsuleSuggestion, HostToPopup, diff --git a/openless-all/app/linux-egui/src/linux_app/settings_save.rs b/openless-all/app/linux-egui/src/linux_app/settings_save.rs index d7e83d1b4..6bb556f03 100644 --- a/openless-all/app/linux-egui/src/linux_app/settings_save.rs +++ b/openless-all/app/linux-egui/src/linux_app/settings_save.rs @@ -137,6 +137,12 @@ impl OpenLessEguiApp { self.snapshot = Some(backend.snapshot()); } self.hydrate_text_fields = true; + // 设置写入是「用户改了东西但看起来没保存」类问题的分界线: + // 成功一条 debug,失败一条 warn(带字段数),不问就不知道卡在哪一段。 + match &result { + Ok(()) => log::debug!("[settings] saved request={request}"), + Err(error) => log::warn!("[settings] save request={request} failed: {error}"), + } match result { Ok(()) => { self.status = tr_l10n(self.lang, "status.settings_saved").to_string(); @@ -247,10 +253,40 @@ impl OpenLessEguiApp { field: frontend::view_model::SettingsComboField, index: usize, ) { + // 日志级别是宿主本地设置(`/logs/level`),不经过 Core 偏好, + // 因此要放在下面 `self.preferences` 的守卫之前 —— 否则偏好还没加载时 + // 连日志级别都改不了。 + if matches!(field, frontend::view_model::SettingsComboField::LogLevel) { + let Some(backend) = self.backend() else { + return; + }; + let level = ["info", "debug", "trace"] + .get(index) + .copied() + .unwrap_or("info"); + let data_dir = backend.config().data_dir.clone(); + match openless_linux_egui::write_log_level(&data_dir, level) { + Ok(parsed) => { + self.frontend_vm.settings.log_level = index; + log::info!( + "[logging] level set to {} (takes effect on the next start)", + openless_linux_egui::level_name(parsed) + ); + self.status = tr_l10n(self.lang, "status.log_level_saved").to_string(); + } + Err(error) => { + log::warn!("[logging] failed to persist the level: {error}"); + self.status = error.to_string(); + } + } + return; + } let Some(preferences) = self.preferences.as_mut() else { return; }; match field { + // 已在函数开头处理(不走 Core 偏好)。 + frontend::view_model::SettingsComboField::LogLevel => {} frontend::view_model::SettingsComboField::Theme => { preferences.theme_mode = match index { 0 => openless_core::shared_types::ThemeMode::System, @@ -673,13 +709,15 @@ impl OpenLessEguiApp { } frontend::view_model::SettingsActionField::ExportDiagnostics => { if let Some(backend) = self.backend() { - let source = openless_linux_egui::log_path(&backend.config().data_dir); + let data_dir = backend.config().data_dir.clone(); let lang = self.lang; self.spawn(async move { let destination = tokio::task::spawn_blocking(|| { rfd::FileDialog::new() - .add_filter("Log", &["log"]) - .set_file_name("openless.log") + // 导出的是「当前 + 全部轮转历史」,默认名字别再叫 openless.log, + // 否则用户会以为是那个单文件。 + .add_filter("Log", &["log", "txt"]) + .set_file_name("openless-diagnostics.log") .save_file() }) .await @@ -696,7 +734,7 @@ impl OpenLessEguiApp { ) })?; tokio::task::spawn_blocking(move || { - openless_linux_egui::export_error_log(&source, &destination) + openless_linux_egui::export_error_logs(&data_dir, &destination) }) .await .map_err(|error| { diff --git a/openless-all/app/linux-egui/src/linux_app/window.rs b/openless-all/app/linux-egui/src/linux_app/window.rs index 34dd03e56..fe2ba3712 100644 --- a/openless-all/app/linux-egui/src/linux_app/window.rs +++ b/openless-all/app/linux-egui/src/linux_app/window.rs @@ -208,7 +208,7 @@ impl OpenLessEguiApp { self.pending_ui_actions.push(*action); } WindowToHost::Hotkey { sequence, edge } => { - log::info!("[hotkey] local edge from the UI window #{sequence}: {edge:?}"); + log::debug!("[hotkey] local edge from the UI window #{sequence}: {edge:?}"); self.pending_local_hotkeys .push((std::time::Instant::now(), edge)); } @@ -584,7 +584,8 @@ impl UiClientApp { let count = self.latency_samples.len(); let max = self.latency_samples.iter().copied().max().unwrap_or(0); let sum: u128 = self.latency_samples.iter().sum(); - log::info!( + // 每 20 次探针一条;它是仪表,不是事件,走 debug。 + log::debug!( "[ui-client] ipc round-trip avg={}ms max={max}ms over {count} probes (last #{sequence})", sum / count as u128 ); @@ -802,7 +803,7 @@ impl eframe::App for UiClientApp { } } if ui_debug_enabled() && !actions.is_empty() { - log::info!("[ui-client] actions from the renderer: {actions:?}"); + log::debug!("[ui-client] actions from the renderer: {actions:?}"); } self.dispatch(actions, &ctx); self.ping_if_due(); diff --git a/openless-all/app/linux-egui/src/logging.rs b/openless-all/app/linux-egui/src/logging.rs index ed7418812..e24752798 100644 --- a/openless-all/app/linux-egui/src/logging.rs +++ b/openless-all/app/linux-egui/src/logging.rs @@ -1,55 +1,385 @@ +//! Linux egui 的日志后端。 +//! +//! 两个进程(宿主 `openless`、UI 窗口 `openless --ui-client`)都写同一个 +//! `$XDG_DATA/openless/logs/openless.log`,这样「窗口进程怎么没了」这类问题 +//! 两端的记录在同一处。 +//! +//! 三条约定,缺一条日志就会退化成没人看的噪声: +//! +//! 1. **级别可调,不用重新编译**。`OPENLESS_LOG`(或 `RUST_LOG`)决定过滤, +//! 例如 `OPENLESS_LOG=debug`、`OPENLESS_LOG=openless_core=debug,info`。 +//! 默认 `info` —— 发布版看不出问题的时候,用户可以只加一个环境变量重启复现。 +//! 2. **周期心跳不许占满文件**。日志是 append + 轮转,任何每 10 秒一条的 +//! 「我还在」都会在一天内吃掉整个配额,把真正的错误挤出去。心跳走 `debug`, +//! `info` 只留状态变化与低频存活证明(见 `log_pump_heartbeat`)。 +//! 3. **`error` 只写失败**,不写进度。轮转后仍有 3 份历史,够回溯一次事故。 + use std::path::{Path, PathBuf}; +use std::sync::OnceLock; + +// 导出只报告已安装的规则,不把待重启的设置误当成生效配置。 +static ACTIVE_FILTER: OnceLock = OnceLock::new(); -const ROTATE_LIMIT_BYTES: u64 = 5 * 1024 * 1024; +/// 单文件上限。整个日志目录最多 `ROTATE_KEEP + 1` 份,即 8 MiB。 +const ROTATE_LIMIT_BYTES: u64 = 2 * 1024 * 1024; +/// 保留的历史份数:`openless.log.1` … `.3`。 +const ROTATE_KEEP: usize = 3; +/// 无法解析 `OPENLESS_LOG` 时的默认级别。 +const DEFAULT_LEVEL: log::LevelFilter = log::LevelFilter::Info; +/// 设置页写入的级别文件名,位于 `/logs/level`。 +/// 环境变量仍然优先:临时排查不该被上一次的界面设置挡住。 +const LEVEL_FILE_NAME: &str = "level"; pub fn log_path(data_dir: &Path) -> PathBuf { data_dir.join("logs").join("openless.log") } +/// 环境变量名:优先 `OPENLESS_LOG`,兼容 Rust 生态惯用的 `RUST_LOG`。 +const ENV_KEYS: [&str; 2] = ["OPENLESS_LOG", "RUST_LOG"]; + pub fn init_file_logger(data_dir: &Path) -> Result { - use simplelog::{ - ColorChoice, CombinedLogger, ConfigBuilder, LevelFilter, TermLogger, TerminalMode, - WriteLogger, - }; + use simplelog::{ColorChoice, SharedLogger, TermLogger, TerminalMode, WriteLogger}; let path = log_path(data_dir); let parent = path.parent().ok_or("log path has no parent")?; std::fs::create_dir_all(parent).map_err(|error| error.to_string())?; - rotate_if_needed(&path).map_err(|error| error.to_string())?; + // 只有宿主轮转:UI 窗口进程若是也有资格改名,宿主手里的文件句柄会指向被 + // 改名的 inode,之后的宿主管日志就写进 `.1` 里了。 + let rotated = if is_ui_client_process() { + false + } else { + rotate_if_needed(&path).map_err(|error| error.to_string())? + }; let file = std::fs::OpenOptions::new() .create(true) .append(true) .open(&path) .map_err(|error| error.to_string())?; - let config = ConfigBuilder::new().set_time_format_rfc3339().build(); - CombinedLogger::init(vec![ + + let filter = FilterSpec::resolve(data_dir); + let config = base_config(); + let sinks: Vec> = vec![ + // 终端上也用同一份过滤结果,级别再放宽到 Trace 交给 FilterSpec 决定。 TermLogger::new( - LevelFilter::Info, + log::LevelFilter::Trace, config.clone(), TerminalMode::Mixed, ColorChoice::Auto, ), - WriteLogger::new(LevelFilter::Info, config, file), - ]) - .map_err(|error| error.to_string())?; - log::info!("Linux egui file logger ready: {}", path.display()); + WriteLogger::new(log::LevelFilter::Trace, config, file), + ]; + + let logger = FilteredLogger { + sinks, + spec: filter.clone(), + }; + log::set_boxed_logger(Box::new(logger)).map_err(|error| error.to_string())?; + log::set_max_level(filter.max_level()); + let description = filter.describe(); + let _ = ACTIVE_FILTER.set(filter); + + log::info!( + "Linux egui logger ready: level={description} rotated={rotated} path={}", + path.display() + ); Ok(path) } -fn rotate_if_needed(path: &Path) -> std::io::Result<()> { +fn base_config() -> simplelog::Config { + use simplelog::{ConfigBuilder, LevelFilter, ThreadLogMode}; + // simplelog 的 builder 方法是 `&mut self` 风格,先持有再链式调用。 + let mut builder = ConfigBuilder::new(); + builder.set_time_format_rfc3339(); + // 模块名一直在,定位「哪一层的日志」不用猜。 + // simplelog 的判据是 `config.target <= record.level()`,级别越小越宽松, + // 所以「始终打印」要设在 Error(最严格端),设成 Trace 反而不打印。 + builder.set_target_level(LevelFilter::Error); + // 线程与源码位置只在 debug 及以上出现,避免 info 行变长。 + builder.set_thread_level(LevelFilter::Debug); + builder.set_thread_mode(ThreadLogMode::Names); + builder.set_location_level(LevelFilter::Debug); + // 用户在 +08:00,日志却是 UTC 的 `Z`:让时间戳落到本地时区。 + // 判定不出来(Err)就保持 UTC,不影响其余配置。 + let _ = builder.set_time_offset_to_local(); + builder.build() +} + +/// 日志过滤规则:一个默认级别 + 若干 `模块前缀=级别` 覆盖。 +#[derive(Clone)] +struct FilterSpec { + default: log::LevelFilter, + overrides: Vec<(String, log::LevelFilter)>, +} + +impl FilterSpec { + /// 优先级:`OPENLESS_LOG`/`RUST_LOG` → 设置里存的级别 → `info`。 + fn resolve(data_dir: &Path) -> Self { + for key in ENV_KEYS { + if let Ok(value) = std::env::var(key) { + return Self::parse(&value).unwrap_or(Self { + default: DEFAULT_LEVEL, + overrides: Vec::new(), + }); + } + } + if let Some(level) = read_log_level(data_dir) { + return Self { + default: level, + overrides: Vec::new(), + }; + } + Self { + default: DEFAULT_LEVEL, + overrides: Vec::new(), + } + } + + /// 解析 `debug` / `info,openless_core=debug` / `OPENLESS_LOG=*`。 + /// 任何一条无法理解的片段都退回默认级别:宁可多记,不可静默少记。 + fn parse(value: &str) -> Option { + let mut default = None; + let mut overrides = Vec::new(); + for piece in value.split(',') { + let piece = piece.trim(); + if piece.is_empty() { + continue; + } + let (target, level) = match piece.split_once('=') { + Some((target, level)) => (Some(target.trim()), level.trim()), + None => (None, piece), + }; + let level = parse_level(level)?; + match target { + Some(target) if !target.is_empty() && target != "*" => { + overrides.push((target.to_string(), level)); + } + _ => default = Some(level), + } + } + Some(Self { + default: default.unwrap_or(DEFAULT_LEVEL), + overrides, + }) + } + + fn level_for(&self, target: &str) -> log::LevelFilter { + // 最长匹配优先:`openless_core::asr` 比 `openless_core` 更具体。 + let mut best: Option<(usize, log::LevelFilter)> = None; + for (prefix, level) in &self.overrides { + if target == prefix || target.starts_with(&format!("{prefix}::")) { + let len = prefix.len(); + if best.is_none_or(|(best_len, _)| len >= best_len) { + best = Some((len, *level)); + } + } + } + best.map(|(_, level)| level).unwrap_or(self.default) + } + + fn max_level(&self) -> log::LevelFilter { + self.overrides + .iter() + .map(|(_, level)| *level) + .chain(std::iter::once(self.default)) + .max() + .unwrap_or(DEFAULT_LEVEL) + } + + fn describe(&self) -> String { + let overrides = self + .overrides + .iter() + .map(|(target, level)| format!("{target}={}", level_label(*level))) + .collect::>(); + if overrides.is_empty() { + level_label(self.default).to_string() + } else { + format!("{} ({})", level_label(self.default), overrides.join(",")) + } + } +} + +fn parse_level(value: &str) -> Option { + match value.trim().to_ascii_lowercase().as_str() { + "off" => Some(log::LevelFilter::Off), + "error" => Some(log::LevelFilter::Error), + "warn" | "warning" => Some(log::LevelFilter::Warn), + "info" => Some(log::LevelFilter::Info), + "debug" => Some(log::LevelFilter::Debug), + "trace" => Some(log::LevelFilter::Trace), + _ => None, + } +} + +/// 设置页保存的日志级别;文件不存在或内容无法识别时返回 `None`。 +pub fn read_log_level(data_dir: &Path) -> Option { + let path = data_dir.join("logs").join(LEVEL_FILE_NAME); + let raw = std::fs::read_to_string(path).ok()?; + parse_level(raw.trim()) +} + +/// 把级别写进 `/logs/level`,下次启动生效。 +pub fn write_log_level(data_dir: &Path, level: &str) -> std::io::Result { + let Some(parsed) = parse_level(level) else { + return Err(std::io::Error::new( + std::io::ErrorKind::InvalidInput, + format!("unknown log level: {level}"), + )); + }; + let dir = data_dir.join("logs"); + std::fs::create_dir_all(&dir)?; + crate::atomic_save(&dir.join(LEVEL_FILE_NAME), level_name(parsed).as_bytes()) + .map_err(|error| std::io::Error::other(error.to_string()))?; + Ok(parsed) +} + +/// 级别的稳定名称:文件名、设置项与日志首行都用它,避免各自拼写。 +pub fn level_name(level: log::LevelFilter) -> &'static str { + level_label(level) +} + +fn level_label(level: log::LevelFilter) -> &'static str { + match level { + log::LevelFilter::Off => "off", + log::LevelFilter::Error => "error", + log::LevelFilter::Warn => "warn", + log::LevelFilter::Info => "info", + log::LevelFilter::Debug => "debug", + log::LevelFilter::Trace => "trace", + } +} + +/// 把 `FilterSpec` 套在所有 sink 前面。simplelog 自身只支持单一级别, +/// 按模块区分级别得在它外面做一层。 +struct FilteredLogger { + sinks: Vec>, + spec: FilterSpec, +} + +impl log::Log for FilteredLogger { + fn enabled(&self, metadata: &log::Metadata) -> bool { + metadata.level() <= self.spec.level_for(metadata.target()) + } + + fn log(&self, record: &log::Record) { + if !self.enabled(record.metadata()) { + return; + } + for sink in &self.sinks { + sink.log(record); + } + } + + fn flush(&self) { + for sink in &self.sinks { + sink.flush(); + } + } +} + +/// UI 窗口进程由宿主拉起,参数里带 `--ui-client`。 +fn is_ui_client_process() -> bool { + std::env::args().any(|arg| arg == "--ui-client") +} + +/// 按 `.log` → `.1` → … → `.ROTATE_KEEP` 依次后移,最老的一份被丢弃。 +/// 返回是否真的轮转过。 +fn rotate_if_needed(path: &Path) -> std::io::Result { let Ok(metadata) = std::fs::metadata(path) else { - return Ok(()); + return Ok(false); }; if metadata.len() <= ROTATE_LIMIT_BYTES { - return Ok(()); + return Ok(false); } - let archive = path.with_file_name("openless.log.1"); - match std::fs::remove_file(&archive) { + let archive = |index: usize| path.with_file_name(format!("openless.log.{index}")); + // 先把最老的删掉,再逐级改名,最后把当前文件挪成 `.1`。 + match std::fs::remove_file(archive(ROTATE_KEEP)) { Ok(()) => {} Err(error) if error.kind() == std::io::ErrorKind::NotFound => {} Err(error) => return Err(error), } - std::fs::rename(path, archive) + for index in (1..ROTATE_KEEP).rev() { + match std::fs::rename(archive(index), archive(index + 1)) { + Ok(()) => {} + Err(error) if error.kind() == std::io::ErrorKind::NotFound => {} + Err(error) => return Err(error), + } + } + std::fs::rename(path, archive(1))?; + Ok(true) +} + +/// 导出「当前日志 + 全部轮转历史」到单个文件。 +/// +/// 只导出 `openless.log` 时,用户报的问题几乎总是发生在轮转之后 —— 现场刚好被 +/// 切进 `.1` 而导出里没有。这里按 `.3` → `.2` → `.1` → 当前的顺序拼接(时间 +/// 正序),每段加分隔头,并在最前面写明版本、系统、生效级别与导出时间, +/// 省掉「你用的哪个版本」这一轮往返。 +pub fn export_error_logs(data_dir: &Path, destination: &Path) -> Result<(), crate::DesktopError> { + let current = log_path(data_dir); + let mut out = String::new(); + out.push_str("# OpenLess Linux diagnostics\n"); + out.push_str(&format!("version: {}\n", env!("OPENLESS_APP_VERSION"))); + out.push_str(&format!( + "os: {} {}\n", + std::env::consts::OS, + std::env::consts::ARCH + )); + out.push_str(&format!( + "level: {}\n", + ACTIVE_FILTER + .get() + .map(FilterSpec::describe) + .unwrap_or_else(|| "unknown (logger not initialized)".to_string()) + )); + out.push_str(&format!( + "exported_at: {}\n\n", + time::OffsetDateTime::now_local() + .unwrap_or_else(|_| time::OffsetDateTime::now_utc()) + .format(&time::format_description::well_known::Rfc3339) + .unwrap_or_default() + )); + + let mut exported = 0usize; + for index in (1..=ROTATE_KEEP).rev() { + let path = current.with_file_name(format!("openless.log.{index}")); + if append_log_section(&mut out, &path, &format!("openless.log.{index}"))? { + exported += 1; + } + } + if append_log_section(&mut out, ¤t, "openless.log")? { + exported += 1; + } + if exported == 0 { + return Err(crate::DesktopError::Io { + operation: "read error log", + source: std::io::Error::new(std::io::ErrorKind::NotFound, "no log file yet"), + }); + } + crate::atomic_save(destination, out.as_bytes()).map(|_| ()) +} + +fn append_log_section( + out: &mut String, + path: &Path, + label: &str, +) -> Result { + match std::fs::read(path) { + Ok(bytes) => { + out.push_str(&format!("===== {label} =====\n")); + out.push_str(&String::from_utf8_lossy(&bytes)); + if !out.ends_with('\n') { + out.push('\n'); + } + out.push('\n'); + Ok(true) + } + Err(error) if error.kind() == std::io::ErrorKind::NotFound => Ok(false), + Err(source) => Err(crate::DesktopError::Io { + operation: "read error log", + source, + }), + } } pub fn export_error_log(source: &Path, destination: &Path) -> Result<(), crate::DesktopError> { @@ -64,6 +394,221 @@ pub fn export_error_log(source: &Path, destination: &Path) -> Result<(), crate:: mod tests { use super::*; + fn run_in_child(name: &str) -> bool { + const CHILD_ENV: &str = "OPENLESS_LOG_TEST_CHILD"; + if std::env::var(CHILD_ENV).as_deref() == Ok(name) { + return false; + } + let output = std::process::Command::new(std::env::current_exe().unwrap()) + .args([ + "--exact", + &format!("logging::tests::{name}"), + "--nocapture", + "--test-threads=1", + ]) + .env(CHILD_ENV, name) + .env_remove("OPENLESS_LOG_RESTART_ROOT") + .env_remove("OPENLESS_LOG") + .env_remove("RUST_LOG") + .output() + .expect("launch isolated logging regression"); + let stdout = String::from_utf8_lossy(&output.stdout); + let stderr = String::from_utf8_lossy(&output.stderr); + assert!( + output.status.success(), + "isolated logging regression failed: {}\n{stdout}\n{stderr}", + output.status + ); + assert!( + stdout.contains("test result: ok. 1 passed; 0 failed"), + "{stdout}" + ); + true + } + + fn temp_dir() -> PathBuf { + let root = std::env::temp_dir().join(format!("openless-log-test-{}", uuid::Uuid::new_v4())); + std::fs::create_dir_all(root.join("logs")).unwrap(); + root + } + + #[test] + fn resolves_configuration_in_priority_order() { + if run_in_child("resolves_configuration_in_priority_order") { + return; + } + let cases = [ + (None, None, None, "info"), + (None, None, Some("debug"), "debug"), + (None, None, Some("loud"), "info"), + (Some("debug"), Some("off"), Some("trace"), "debug"), + ( + Some("debug,openless_core=loud"), + Some("off"), + Some("off"), + "info", + ), + (Some("loud"), None, Some("off"), "info"), + (None, Some("loud"), Some("off"), "info"), + (None, Some("debug"), Some("off"), "debug"), + (Some("off"), Some("debug"), Some("trace"), "off"), + (None, Some("off"), Some("debug"), "off"), + (Some(""), Some("off"), Some("debug"), "info"), + ]; + for (openless, rust, saved, expected) in cases { + let root = temp_dir(); + for (key, value) in [("OPENLESS_LOG", openless), ("RUST_LOG", rust)] { + match value { + Some(value) => std::env::set_var(key, value), + None => std::env::remove_var(key), + } + } + if let Some(saved) = saved { + std::fs::write(root.join("logs/level"), saved).unwrap(); + } + assert_eq!( + FilterSpec::resolve(&root).describe(), + expected, + "OPENLESS_LOG={openless:?}, RUST_LOG={rust:?}, saved={saved:?}" + ); + std::fs::remove_dir_all(root).unwrap(); + } + } + + fn exported_text(root: &Path) -> String { + log::logger().flush(); + let destination = root.join("diagnostics.log"); + export_error_logs(root, &destination).unwrap(); + std::fs::read_to_string(destination).unwrap() + } + + #[test] + fn exports_the_active_rust_log_filter() { + if run_in_child("exports_the_active_rust_log_filter") { + return; + } + let root = temp_dir(); + write_log_level(&root, "off").unwrap(); + std::env::set_var("RUST_LOG", "debug"); + init_file_logger(&root).unwrap(); + log::debug!("rust-log-debug-probe"); + let text = exported_text(&root); + assert!(text.lines().any(|line| line == "level: debug"), "{text}"); + assert!(text.contains("rust-log-debug-probe")); + std::fs::remove_dir_all(root).unwrap(); + } + + #[test] + fn exports_module_overrides_and_filters_their_boundaries() { + if run_in_child("exports_module_overrides_and_filters_their_boundaries") { + return; + } + let root = temp_dir(); + std::env::set_var( + "OPENLESS_LOG", + "info,openless_core=debug,openless_core::asr=warn", + ); + init_file_logger(&root).unwrap(); + log::debug!(target: "openless_core::api", "core-debug-probe"); + log::debug!(target: "openless_core::asr", "asr-debug-probe"); + log::debug!(target: "openless_core_extra", "lookalike-debug-probe"); + log::warn!(target: "openless_core::asr", "asr-warn-probe"); + let text = exported_text(&root); + assert!( + text.lines() + .any(|line| line == "level: info (openless_core=debug,openless_core::asr=warn)"), + "{text}" + ); + assert!(text.contains("core-debug-probe")); + assert!(text.contains("asr-warn-probe")); + assert!(!text.contains("asr-debug-probe")); + assert!(!text.contains("lookalike-debug-probe")); + std::fs::remove_dir_all(root).unwrap(); + } + + #[test] + fn exports_the_active_level_until_restart() { + const NAME: &str = "exports_the_active_level_until_restart"; + const ROOT_ENV: &str = "OPENLESS_LOG_RESTART_ROOT"; + if run_in_child(NAME) { + return; + } + if let Some(root) = std::env::var_os(ROOT_ENV) { + let root = PathBuf::from(root); + init_file_logger(&root).unwrap(); + log::debug!("restarted-debug-probe"); + let text = exported_text(&root); + assert!(text.lines().any(|line| line == "level: debug"), "{text}"); + assert!(text.contains("restarted-debug-probe")); + return; + } + let root = temp_dir(); + write_log_level(&root, "info").unwrap(); + init_file_logger(&root).unwrap(); + write_log_level(&root, "debug").unwrap(); + log::debug!("pending-debug-probe"); + let text = exported_text(&root); + assert!(text.lines().any(|line| line == "level: info"), "{text}"); + assert!(!text.contains("pending-debug-probe")); + let output = std::process::Command::new(std::env::current_exe().unwrap()) + .args([ + "--exact", + "logging::tests::exports_the_active_level_until_restart", + "--nocapture", + "--test-threads=1", + ]) + .env("OPENLESS_LOG_TEST_CHILD", NAME) + .env(ROOT_ENV, &root) + .env_remove("OPENLESS_LOG") + .env_remove("RUST_LOG") + .output() + .unwrap(); + let stdout = String::from_utf8_lossy(&output.stdout); + let stderr = String::from_utf8_lossy(&output.stderr); + assert!(output.status.success(), "{stdout}\n{stderr}"); + assert!( + stdout.contains("test result: ok. 1 passed; 0 failed"), + "{stdout}" + ); + std::fs::remove_dir_all(root).unwrap(); + } + + #[test] + fn exports_existing_logs_without_an_initialized_logger() { + if run_in_child("exports_existing_logs_without_an_initialized_logger") { + return; + } + let root = temp_dir(); + std::fs::write(log_path(&root), "existing-log-probe\n").unwrap(); + write_log_level(&root, "debug").unwrap(); + let text = exported_text(&root); + assert!( + text.lines() + .any(|line| line == "level: unknown (logger not initialized)"), + "{text}" + ); + assert!(text.contains("existing-log-probe")); + std::fs::remove_dir_all(root).unwrap(); + } + + #[test] + fn failed_initialization_preserves_the_active_filter() { + if run_in_child("failed_initialization_preserves_the_active_filter") { + return; + } + let root = temp_dir(); + std::env::set_var("OPENLESS_LOG", "debug"); + init_file_logger(&root).unwrap(); + std::env::set_var("OPENLESS_LOG", "info"); + assert!(init_file_logger(&root).is_err()); + assert_eq!(log::max_level(), log::LevelFilter::Debug); + log::debug!("still-debug-after-failed-init"); + let text = exported_text(&root); + assert!(text.lines().any(|line| line == "level: debug"), "{text}"); + assert!(text.contains("still-debug-after-failed-init")); + std::fs::remove_dir_all(root).unwrap(); + } + #[test] fn exports_the_current_log_with_atomic_save() { let root = std::env::temp_dir().join(format!( @@ -80,4 +625,118 @@ mod tests { assert_eq!(std::fs::read(destination).unwrap(), b"diagnostic\n"); std::fs::remove_dir_all(root).unwrap(); } + + #[test] + fn exports_every_rotated_file_with_a_header() { + let root = std::env::temp_dir().join(format!( + "openless-linux-log-export-all-{}", + uuid::Uuid::new_v4().simple() + )); + let logs = root.join("logs"); + std::fs::create_dir_all(&logs).unwrap(); + std::fs::write(logs.join("openless.log"), b"newest\n").unwrap(); + std::fs::write(logs.join("openless.log.1"), b"older\n").unwrap(); + std::fs::write(logs.join("openless.log.2"), b"oldest\n").unwrap(); + let destination = root.join("diagnostics.log"); + + export_error_logs(&root, &destination).unwrap(); + let text = std::fs::read_to_string(&destination).unwrap(); + + assert!(text.starts_with("# OpenLess Linux diagnostics\n")); + assert!(text.contains("version: ")); + // 时间正序:`.2` 在 `.1` 之前,当前文件在最后。 + let oldest = text.find("oldest").unwrap(); + let older = text.find("older").unwrap(); + let newest = text.find("newest").unwrap(); + assert!( + oldest < older && older < newest, + "sections must be chronological" + ); + assert!(text.contains("===== openless.log.2 =====")); + + std::fs::remove_dir_all(root).unwrap(); + } + + #[test] + fn persists_the_level_for_the_next_start() { + let root = std::env::temp_dir().join(format!( + "openless-linux-log-level-{}", + uuid::Uuid::new_v4().simple() + )); + assert_eq!(read_log_level(&root), None); + assert_eq!( + write_log_level(&root, "debug").unwrap(), + log::LevelFilter::Debug + ); + assert_eq!(read_log_level(&root), Some(log::LevelFilter::Debug)); + assert!(write_log_level(&root, "loud").is_err()); + std::fs::remove_dir_all(root).unwrap(); + } + + #[test] + fn parses_plain_and_per_module_levels() { + let spec = FilterSpec::parse("debug").unwrap(); + assert_eq!(spec.level_for("openless_core"), log::LevelFilter::Debug); + + let spec = FilterSpec::parse("info,openless_core=debug").unwrap(); + assert_eq!( + spec.level_for("openless_core::asr"), + log::LevelFilter::Debug + ); + assert_eq!( + spec.level_for("openless_linux_egui"), + log::LevelFilter::Info + ); + + // 更具体的模块前缀优先。 + let spec = FilterSpec::parse("openless_core=debug,openless_core::asr=warn").unwrap(); + assert_eq!( + spec.level_for("openless_core::asr::volcengine"), + log::LevelFilter::Warn + ); + assert_eq!( + spec.level_for("openless_core::api"), + log::LevelFilter::Debug + ); + } + + #[test] + fn rejects_garbage_instead_of_silencing_everything() { + assert!(FilterSpec::parse("loud").is_none()); + } + + #[test] + fn rotates_into_numbered_archives_and_drops_the_oldest() { + let root = std::env::temp_dir().join(format!( + "openless-linux-log-rotate-{}", + uuid::Uuid::new_v4().simple() + )); + std::fs::create_dir_all(&root).unwrap(); + let path = root.join("openless.log"); + std::fs::write(&path, vec![b'x'; (ROTATE_LIMIT_BYTES + 1) as usize]).unwrap(); + std::fs::write(root.join("openless.log.1"), b"one").unwrap(); + std::fs::write(root.join("openless.log.2"), b"two").unwrap(); + std::fs::write(root.join("openless.log.3"), b"three").unwrap(); + + assert!(rotate_if_needed(&path).unwrap()); + + assert!(!path.exists(), "the current log must have been moved aside"); + assert_eq!( + std::fs::read(root.join("openless.log.1")).unwrap().len(), + (ROTATE_LIMIT_BYTES + 1) as usize + ); + assert_eq!(std::fs::read(root.join("openless.log.2")).unwrap(), b"one"); + assert_eq!(std::fs::read(root.join("openless.log.3")).unwrap(), b"two"); + assert!( + !root.join("openless.log.4").exists(), + "archives beyond ROTATE_KEEP must be dropped" + ); + + // 小于上限时不轮转。 + std::fs::write(&path, b"small").unwrap(); + assert!(!rotate_if_needed(&path).unwrap()); + assert!(path.exists()); + + std::fs::remove_dir_all(root).unwrap(); + } } diff --git a/openless-all/app/linux-egui/src/main.rs b/openless-all/app/linux-egui/src/main.rs index 6daf7ac10..63fe56c4c 100644 --- a/openless-all/app/linux-egui/src/main.rs +++ b/openless-all/app/linux-egui/src/main.rs @@ -7,13 +7,17 @@ mod style_icon; #[cfg(target_os = "linux")] mod ui; -#[cfg(target_os = "linux")] mod linux_app { mod history; use history::HistoryCache; mod settings_save; mod window; use settings_save::SettingsSave; + /// 泵心跳的采样间隔:热键消费停没停,十秒内一定看得出来。 + const PUMP_HEARTBEAT_INTERVAL: std::time::Duration = std::time::Duration::from_secs(10); + /// 状态没有变化时,`info` 级心跳的最低频率(存活证明,不为排查细节服务)。 + const PUMP_HEARTBEAT_INFO_INTERVAL: std::time::Duration = std::time::Duration::from_secs(300); + use std::future::Future; use std::sync::mpsc; use std::sync::Arc; @@ -667,8 +671,13 @@ mod linux_app { vocab_suggestions_checked: std::time::Instant, tray: Option, exit_requested: bool, - /// 上次打「泵心跳」日志的时间。 + /// 上次采样「泵心跳」的时间(每 10 秒一次,与日志级别无关)。 last_pump_heartbeat: std::time::Instant, + /// 上次把心跳写进 `info` 的时间。心跳是每 10 秒一次的存在性证明, + /// 全写 `info` 会在一天内吃满日志配额,把真正的错误挤出去。 + last_pump_heartbeat_info: std::time::Instant, + /// 上次写 `info` 时的状态快照;状态一变就立刻记一条。 + last_pump_heartbeat_snapshot: [bool; 4], window: WindowState, /// 本帧从 UI 收到、待宿主执行的动作(按到达顺序)。 pending_ui_actions: Vec, @@ -903,6 +912,8 @@ mod linux_app { tray, exit_requested: false, last_pump_heartbeat: std::time::Instant::now(), + last_pump_heartbeat_info: std::time::Instant::now(), + last_pump_heartbeat_snapshot: [false; 4], window: WindowState::new(window_should_be_open), pending_ui_actions: Vec::new(), pending_local_hotkeys: Vec::new(), @@ -1022,6 +1033,8 @@ mod linux_app { tray, exit_requested: false, last_pump_heartbeat: std::time::Instant::now(), + last_pump_heartbeat_info: std::time::Instant::now(), + last_pump_heartbeat_snapshot: [false; 4], window: WindowState::new(window_should_be_open), pending_ui_actions: Vec::new(), pending_local_hotkeys: Vec::new(), @@ -2120,7 +2133,7 @@ mod linux_app { } }, PopupSupervisorEvent::Message(PopupToHost::Hotkey { edge, .. }) => { - log::info!("[hotkey] local edge from the {kind:?} panel: {edge:?}"); + log::debug!("[hotkey] local edge from the {kind:?} panel: {edge:?}"); self.pending_local_hotkeys .push((std::time::Instant::now(), edge)); } @@ -4190,25 +4203,42 @@ mod linux_app { /// current-thread 运行时,`spawn` 的任务只在别处 `block_on` 时才被推进, /// 当作后台泵用就是「写完看着对、最小化后照样死」(实测心跳会在窗口 /// 收走的那一刻停)。线程只做一件事:`request_repaint()` 把事件循环戳醒。 - /// 泵心跳:宿主循环每 10s 一条。窗口关掉之后这条心跳**不能**停 —— + /// 泵心跳:宿主循环每 10s 采样一次。窗口关掉之后这条心跳**不能**停 —— /// 停了就说明热键消费与弹窗拉起也没在跑(这正是当初「关窗后热键失效」 - /// 的判据),用户/支持可以直接看日志确认。 + /// 的判据)。 + /// + /// 采样归采样,写日志要节流:每 10 秒一条 `info` 是 8640 行/天,轮转后 + /// 整份日志九成以上都是它,真正的错误反而被挤出去。所以**状态变化立刻 + /// 记一条 `info`**(这才是判据),状态没变时只每 + /// [`PUMP_HEARTBEAT_INFO_INTERVAL`] 留一条存活证明,其余走 `debug`。 fn log_pump_heartbeat(&mut self, ctx: &egui::Context) { self.tick_vocab_suggestions(); - if self.last_pump_heartbeat.elapsed() < std::time::Duration::from_secs(10) { + if self.last_pump_heartbeat.elapsed() < PUMP_HEARTBEAT_INTERVAL { return; } self.last_pump_heartbeat = std::time::Instant::now(); // 宿主没有窗口,所以心跳只看「窗口进程还在不在」—— // 这正是关窗后必须继续为 true 的那一项能力。 let _ = ctx; - log::info!( - "[pump] heartbeat window_process={} window_wanted={} tray={} recording={}", + let snapshot = [ self.window.child.is_some(), self.window.should_be_open, self.tray.is_some(), self.recording_phase_active, + ]; + let changed = snapshot != self.last_pump_heartbeat_snapshot; + let due = self.last_pump_heartbeat_info.elapsed() >= PUMP_HEARTBEAT_INFO_INTERVAL; + let message = format!( + "[pump] heartbeat window_process={} window_wanted={} tray={} recording={}", + snapshot[0], snapshot[1], snapshot[2], snapshot[3], ); + if changed || due { + self.last_pump_heartbeat_info = std::time::Instant::now(); + self.last_pump_heartbeat_snapshot = snapshot; + log::info!("{message}"); + } else { + log::debug!("{message}"); + } } /// 当前生效的热键配置(本地匹配与去重都用它)。 @@ -4596,6 +4626,7 @@ mod linux_app { let mut actions = Vec::new(); native.host_actions().drain(|action| actions.push(action)); for intent in launch_intents { + log::info!("[ui-host] launch intent from the user: {intent:?}"); // CLI 的 ToggleQa 与「按一次 QA 热键」等价(Tauri // `dispatch_cli_intent` 把 ToggleQa 直接转给 `handle_qa_hotkey_pressed`), // 所以它既不拉起主窗口,也不走 Core 的 ToggleQa(那条是“切换录音”)。 @@ -4607,7 +4638,6 @@ mod linux_app { self.toggle_qa_panel(); continue; } - log::info!("[ui-host] launch intent from the user: {intent:?}"); launch_intent_window_requested = true; let host = Arc::clone(&host); self.spawn(async move { @@ -5660,6 +5690,15 @@ mod linux_app { // 文本型设置行只在偏好载入 / 外部变更时回灌一次,避免把输入中的 // 内容每帧弹回旧值。 let hydrate_text = std::mem::replace(&mut self.hydrate_text_fields, false); + // 日志级别是宿主本地文件(不在 Core 偏好里),要在借用 vm 之前读。 + let log_level_index = self + .backend() + .and_then(|backend| openless_linux_egui::read_log_level(&backend.config().data_dir)) + .map_or(0, |level| match level { + log::LevelFilter::Debug => 1, + log::LevelFilter::Trace => 2, + _ => 0, + }); let vm = &mut self.frontend_vm; @@ -5840,6 +5879,8 @@ mod linux_app { s.launch_at_login = prefs.launch_at_login; s.streaming_save_clipboard = prefs.streaming_insert_save_clipboard; s.record_audio_for_debug = prefs.record_audio_for_debug; + // 日志级别是宿主本地文件,不在 Core 偏好里;读不到就按 info 显示。 + s.log_level = log_level_index; if hydrate_text { s.history_max_entries = prefs .history_max_entries @@ -10316,8 +10357,9 @@ Internal flags (set by OpenLess itself, not for regular use): let tray_available = tray.is_some(); let native = (|| { let mut config = backend_config()?; - if let Err(error) = openless_linux_egui::init_file_logger(&config.data_dir) { - eprintln!("OpenLess file logger unavailable: {error}"); + match openless_linux_egui::init_file_logger(&config.data_dir) { + Ok(_) => log::info!("[startup] single-instance lock acquired; running as primary"), + Err(error) => eprintln!("OpenLess file logger unavailable: {error}"), } if let Some(error) = tray_error { // 没有托盘 ⇒ 关窗就退出:这是用户行为差异,必须写进启动日志。 @@ -10466,6 +10508,134 @@ Internal flags (set by OpenLess itself, not for regular use): } } + #[test] + fn startup_logging_records_forwarded_intents_without_rotating_again() { + use std::io::Write; + + const CHILD_ENV: &str = "OPENLESS_STARTUP_LOG_TEST_CHILD"; + const TEST: &str = "linux_app::tests::startup_logging_records_forwarded_intents_without_rotating_again"; + if std::env::var_os(CHILD_ENV).as_deref() != Some(std::ffi::OsStr::new("1")) { + let output = std::process::Command::new(std::env::current_exe().unwrap()) + .args(["--exact", TEST, "--nocapture", "--test-threads=1"]) + .env(CHILD_ENV, "1") + .env_remove("OPENLESS_LOG") + .env_remove("RUST_LOG") + .output() + .expect("launch isolated startup logging regression"); + let stdout = String::from_utf8_lossy(&output.stdout); + let stderr = String::from_utf8_lossy(&output.stderr); + assert!(output.status.success(), "{stdout}\n{stderr}"); + assert!( + stdout.contains("test result: ok. 1 passed; 0 failed"), + "{stdout}" + ); + return; + } + let root = tempfile::tempdir().unwrap(); + for key in [ + "XDG_DATA_HOME", + "XDG_CONFIG_HOME", + "XDG_CACHE_HOME", + "XDG_RUNTIME_DIR", + ] { + std::env::set_var(key, root.path()); + } + let runtime_dir = root.path().join("runtime"); + let data_dir = root.path().join("data"); + std::fs::create_dir_all(&runtime_dir).unwrap(); + std::fs::create_dir_all(data_dir.join("logs")).unwrap(); + let path = openless_linux_egui::log_path(&data_dir); + let old_log = vec![b'o'; 2 * 1024 * 1024 + 1]; + std::fs::write(&path, &old_log).unwrap(); + let args = vec!["openless".to_string()]; + let primary = match acquire_broker(&runtime_dir, &args).unwrap() { + BrokerAcquisition::Primary(broker) => Arc::new(broker), + BrokerAcquisition::Forwarded => panic!("the first launch must be primary"), + }; + openless_linux_egui::init_file_logger(&data_dir).unwrap(); + assert!(std::fs::read_to_string(&path) + .unwrap() + .contains("Linux egui logger ready:")); + + let mut app = fixture_app(false); + let host_actions = Arc::new(openless_linux_egui::LinuxHostActions::default()); + let mut dependencies = openless_core::BackendDependencies::unsupported(); + dependencies.host_actions = host_actions.clone(); + dependencies.credential_store = + Arc::new(openless_core::InMemoryCredentialStore::default()); + dependencies.services.remote_input = Arc::new( + openless_core::RemoteInputService::new( + Arc::new(openless_core::testing::RecordingRemoteInputRuntime::default()), + 8443, + "en", + ) + .unwrap(), + ); + let backend = Arc::new( + openless_core::OpenLessBackend::new( + BackendConfig { + data_dir: data_dir.clone(), + ..Default::default() + }, + dependencies, + ) + .unwrap(), + ); + let runtime = openless_linux_egui::LinuxBackendRuntime { + backend: backend.clone(), + host_actions, + settings_runtime: Arc::new(openless_core::settings::NoopSettingsRuntime), + }; + app.native = Some( + app.tokio + .block_on(LinuxNativeRuntime::start( + runtime, + Some(primary.clone()), + None, + )) + .unwrap(), + ); + app.snapshot = Some(backend.snapshot()); + app.preferences = Some(backend.get_preferences()); + // 只测试 QA 的收起分支,不创建真实弹窗或启动录音。 + app.qa_visible = true; + + let mut active = std::fs::OpenOptions::new() + .append(true) + .open(&path) + .unwrap(); + active.write_all(&vec![b'x'; 2 * 1024 * 1024 + 1]).unwrap(); + active.write_all(b"\nactive-file-marker\n").unwrap(); + drop(active); + for args in [ + args, + vec!["openless".to_string(), "--toggle-qa".to_string()], + ] { + assert!(matches!( + acquire_broker(&runtime_dir, &args).unwrap(), + BrokerAcquisition::Forwarded + )); + } + app.poll(&egui::Context::default()); + log::logger().flush(); + let text = std::fs::read_to_string(&path).unwrap(); + for intent in ["ShowMain", "Cli(ToggleQa)"] { + let message = format!("[ui-host] launch intent from the user: {intent}"); + assert_eq!(text.matches(&message).count(), 1, "{message}"); + } + assert!(text.contains("active-file-marker")); + assert!(app.window.should_be_open); + assert!(!app.qa_visible); + assert_eq!( + std::fs::read(data_dir.join("logs/openless.log.1")).unwrap(), + old_log + ); + assert!(!data_dir.join("logs/openless.log.2").exists()); + assert!(!data_dir.join("logs/openless.log.3").exists()); + drop(app); + drop(primary); + } + #[test] fn an_idle_popup_submission_reaches_core_and_displays_failure() { let data_dir = tempfile::tempdir().unwrap(); diff --git a/openless-all/app/linux-egui/src/ui/frontend/settings.rs b/openless-all/app/linux-egui/src/ui/frontend/settings.rs index 5dcd97f23..493a62327 100644 --- a/openless-all/app/linux-egui/src/ui/frontend/settings.rs +++ b/openless-all/app/linux-egui/src/ui/frontend/settings.rs @@ -3210,6 +3210,19 @@ fn advanced(ui: &mut egui::Ui, vm: &mut FrontendViewModel, actions: &mut Vec/logs/level`, + /// 重启后生效;不是 Core 偏好,所以不上云、不影响 Tauri。 + LogLevel, } #[derive(Clone, serde::Serialize, serde::Deserialize, Debug)] @@ -1201,6 +1204,8 @@ pub struct SettingsFields { #[serde(default)] pub llm_thinking_enabled: bool, pub record_audio_for_debug: bool, + /// 日志级别:0 = info,1 = debug,2 = trace。宿主本地设置,不进 Core 偏好。 + pub log_level: usize, pub history_max_entries: String, /// 风格直达快捷键(可录制/停用/移除)。 pub style_pack_hotkeys: Vec, @@ -1268,6 +1273,7 @@ impl Default for SettingsFields { capsule_transcript_font_size: 14, llm_thinking_enabled: false, record_audio_for_debug: false, + log_level: 0, history_max_entries: String::new(), style_pack_hotkeys: Vec::new(), polish_context_window: String::new(), diff --git a/openless-all/app/scripts/egui-logging-contract.test.mjs b/openless-all/app/scripts/egui-logging-contract.test.mjs new file mode 100644 index 000000000..1ff1eb13e --- /dev/null +++ b/openless-all/app/scripts/egui-logging-contract.test.mjs @@ -0,0 +1,191 @@ +// Contract test for the Linux egui logging backend. +// +// Logs are the only thing a user can hand us when the Linux host misbehaves, so +// the backend has to satisfy three properties that are easy to lose in a +// refactor: +// +// 1. The level filter is reachable without a rebuild (`OPENLESS_LOG`). +// 2. Periodic liveness chatter never sits at `info`: a 10 s heartbeat is 8,640 +// lines a day and pushed every real message out of the rotated files. +// 3. `error` means failure. A `stage=` progress tracer logged at `error` makes +// every startup look broken. +// +// The Rust sources are read as text: this test runs in the Linux contract job +// and must not need a compiled tree. +import assert from 'node:assert/strict'; +import { readFileSync } from 'node:fs'; +import { dirname, join, resolve } from 'node:path'; +import { fileURLToPath } from 'node:url'; + +const appRoot = resolve(dirname(fileURLToPath(import.meta.url)), '..'); +const read = (relative) => readFileSync(join(appRoot, relative), 'utf8'); + +const logging = read('linux-egui/src/logging.rs'); +const main = read('linux-egui/src/main.rs'); +const window = read('linux-egui/src/linux_app/window.rs'); +const adapter = read('crates/openless-core/src/cloud_sync_e2ee/adapter.rs'); + +// 1. Level filter from the environment, not a constant baked in at build time. +assert.match( + logging, + /"OPENLESS_LOG"/, + 'logging.rs must read OPENLESS_LOG so a user can turn on debug without a rebuild', +); +assert.match( + logging, + /"RUST_LOG"/, + 'logging.rs must keep honouring RUST_LOG for people who expect the Rust convention', +); +assert.match( + logging, + /log::set_boxed_logger/, + 'logging.rs must install a logger that applies the parsed filter', +); +assert.ok( + !/LevelFilter::Info,\s*\n\s*config\.clone\(\),\s*\n\s*TerminalMode/.test(logging), + 'the terminal sink must not be hard-wired to Info any more', +); + +// 2. Rotation keeps more than a single archive, otherwise one busy day erases +// the incident we are trying to diagnose. +assert.match( + logging, + /const ROTATE_KEEP: usize = [2-9]/, + 'logging.rs must keep at least two log archives', +); + +// 3. The pump heartbeat is throttled: state changes at `info`, the rest at +// `debug`, plus a low-frequency liveness line. +assert.match( + main, + /const PUMP_HEARTBEAT_INFO_INTERVAL[\s\S]{0,80}from_secs\(\d{2,}\)/, + 'the pump heartbeat needs an info-level interval of at least tens of seconds', +); +assert.ok( + !/log::info!\(\s*\n?\s*"\[pump\] heartbeat/.test(main), + 'the 10 s pump heartbeat must not be logged at info unconditionally', +); +assert.match( + main, + /log::debug!\("\{message\}"\)/, + 'the throttled heartbeat must fall back to debug', +); + +// 4. The IPC probe is a gauge, not an event. +assert.ok( + !/log::info!\(\s*\n?\s*"\[ui-client\] ipc round-trip/.test(window), + 'the IPC round-trip probe must stay at debug', +); + +// 5. No progress tracer disguised as a failure. +assert.ok( + !/log::error!\(\s*"\[e2ee-adapter\] stage=/.test(adapter), + 'the e2ee adapter must not log its stage tracers at error level', +); +assert.ok( + !/log::error!\(\s*\n\s*"\[e2ee-adapter\] build start/.test(adapter), + 'the e2ee adapter must not log its build start marker at error level', +); + +// 6. Nothing that looks like a secret may be formatted into a log line. +const logCalls = [...`${main}\n${window}\n${adapter}`.matchAll(/log::(?:error|warn|info|debug|trace)!\(([\s\S]{0,400}?)\);/g)]; +for (const [, body] of logCalls) { + assert.ok( + !/\b(?:api_key|apikey|access_token|refresh_token|client_secret|password|private_key)\s*=/i.test( + body, + ), + `a log line formats what looks like a secret: ${body.trim().slice(0, 120)}`, + ); +} + + +// 7. The level chosen in the UI has to outlive the process, and the export has to +// carry the rotated history - otherwise the file the user sends us is exactly +// the one that no longer contains the incident. +const settingsSave = read('linux-egui/src/linux_app/settings_save.rs'); +assert.match( + logging, + /pub fn write_log_level/, + 'logging.rs must persist the level chosen in the settings UI', +); +assert.match( + logging, + /pub fn read_log_level/, + 'logging.rs must read the persisted level at startup', +); +assert.match( + settingsSave, + /write_log_level\(/, + 'the settings handler must persist the log level', +); +assert.match( + settingsSave, + /export_error_logs\(/, + 'the export action must include the rotated logs, not only the current file', +); +assert.match( + logging, + /pub fn export_error_logs/, + 'logging.rs must provide the multi-file export', +); + +// 8. The gaps that used to make a report unusable: no capture line on success, no +// dictation start, no single-instance outcome. +assert.match( + read('linux-egui/src/audio.rs'), + /"\[audio\] capture started backend=/, + 'capture start must name the backend, device and format that actually won', +); +assert.match( + read('crates/openless-core/src/api.rs'), + /"\[dictation\] start session_id=/, + 'the dictation start boundary must be logged (hotkey pressed but nothing happened)', +); +const brokerStart = main.indexOf(' fn acquire_broker('); +const brokerEnd = main.indexOf(' impl Drop for OpenLessEguiApp', brokerStart); +assert.ok(brokerStart >= 0 && brokerEnd > brokerStart, 'find the single-instance acquisition function'); +assert.doesNotMatch( + main.slice(brokerStart, brokerEnd), + /log::(?:info|warn|error)!/, + 'single-instance acquisition runs before logger initialization; it must not emit lost startup logs', +); +const runStart = main.indexOf(' pub fn run() -> Result<(), String>'); +const runEnd = main.indexOf(' #[cfg(test)]', runStart); +assert.ok(runStart >= 0 && runEnd > runStart, 'find the production startup function'); +const startup = main.slice(runStart, runEnd); +const acquire = startup.indexOf('acquire_broker('); +const forwardedExit = startup.indexOf('BrokerAcquisition::Forwarded => return Ok(())'); +const loggerInit = startup.indexOf('init_file_logger('); +const primaryLog = startup.indexOf('[startup] single-instance lock acquired'); +assert.ok( + acquire >= 0 && forwardedExit > acquire && loggerInit > forwardedExit && primaryLog > loggerInit, + 'only the primary may initialize/rotate logs, and its role must be logged after initialization', +); +assert.match( + startup, + /match openless_linux_egui::init_file_logger\([^)]*\)\s*\{\s*Ok\([^)]*\)\s*=>\s*(?:\{\s*)?log::info!/, + 'the primary startup line must only be emitted after successful logger initialization', +); +const intentLoopStart = main.indexOf(' for intent in launch_intents {'); +const intentLoopEnd = main.indexOf(' // 本地边沿先于插件信号处理', intentLoopStart); +assert.ok(intentLoopStart >= 0 && intentLoopEnd > intentLoopStart, 'find the primary intent-consumption loop'); +const intentLoop = main.slice(intentLoopStart, intentLoopEnd); +const receivedLog = intentLoop.indexOf('[ui-host] launch intent from the user:'); +assert.ok( + receivedLog >= 0 && receivedLog < intentLoop.indexOf('if matches!('), + 'the primary must log forwarded intents before any dispatch branch, including ToggleQa', +); + +// 9. Per-event chatter must not sit at info. +assert.ok( + !/log::info!\("\[transcript\] partial emitted/.test( + read('crates/openless-core/src/dictation_engine.rs'), + ), + 'each streaming partial must not be logged at info', +); +assert.ok( + !/log::info!\("\[hotkey\] local edge/.test(main), + 'per-keystroke hotkey edges must stay at debug', +); + +console.log('egui-logging contract test passed');