diff --git a/Cargo.lock b/Cargo.lock index a37b7fd..53a0df6 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2222,7 +2222,7 @@ dependencies = [ [[package]] name = "mhrv-rs" -version = "1.8.1" +version = "1.8.2" dependencies = [ "base64 0.22.1", "bytes", diff --git a/Cargo.toml b/Cargo.toml index 05d2ac0..da64e63 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "mhrv-rs" -version = "1.8.1" +version = "1.8.2" edition = "2021" description = "Rust port of MasterHttpRelayVPN -- DPI bypass via Google Apps Script relay with domain fronting" license = "MIT" diff --git a/docs/changelog/v1.8.2.md b/docs/changelog/v1.8.2.md new file mode 100644 index 0000000..9350c9c --- /dev/null +++ b/docs/changelog/v1.8.2.md @@ -0,0 +1,6 @@ + +• اصلاح log level در UI binary (Windows + Android) ([#401](https://github.com/therealaleph/MasterHttpRelayVPN-RUST/issues/401)): قبلاً `mhrv-rs-ui` (و Android) فیلتر tracing رو فقط از `RUST_LOG` env var یا default `info,hyper=warn` می‌خوند — مقدار `log_level` در `config.json` در عمل ignore می‌شد. فرم UI combobox `log_level` داشت ولی هیچ‌جا به subscriber اعمال نمی‌شد. حالا precedence اینه: `RUST_LOG` (اگر set باشد) > `config.log_level` > `info,hyper=warn`. علاوه بر این Save در UI الان log level رو live اعمال می‌کنه (بدون نیاز به restart) از طریق reload handle. CLI `mhrv-rs` از قبل درست کار می‌کرد — این فقط fix UI bin بود. +• پیغام تشخیص decoy ملایم‌تر — به‌جای assert AUTH_KEY mismatch، چهار علت ممکن enumerate می‌کنه ([#404](https://github.com/therealaleph/MasterHttpRelayVPN-RUST/issues/404)): @w0l4i گزارش داد همان `script_id` گاهی decoy و گاهی موفقیت برمی‌گرده در یک دقیقه — یعنی NOT AUTH_KEY mismatch (اگر بود ۱۰۰٪ fail می‌گرفت). تحقیق نشون داد body string `"The script completed but did not return anything"` اختصاصی به decoy v1.8.0 ما نیست — Apps Script همان body رو در ۴ سناریو برمی‌گردونه: (۱) AUTH_KEY mismatch (decoy ما، intentional)، (۲) Apps Script execution timeout یا quota tear، (۳) Google-side internal hiccup، (۴) ISP-side response truncation (#313 pattern). Error message v1.8.1 false positive داشت در سناریو ۲-۴. حالا پیغام: "got the v1.8.0 decoy/placeholder body — could be (1) AUTH_KEY mismatch, (2) Apps Script execution timeout/quota tear, (3) Apps Script internal hiccup, (4) ISP-side response truncation. Set DIAGNOSTIC_MODE=true to disambiguate (1) — only AUTH_KEY mismatch returns this body in diagnostic mode." کاربر action درست رو کشف می‌کنه. +--- +• Fix log level on the UI binary (Windows + Android) ([#401](https://github.com/therealaleph/MasterHttpRelayVPN-RUST/issues/401)): previously `mhrv-rs-ui` (and Android, which uses the same JNI path) installed its tracing filter from `RUST_LOG` only — falling back to `info,hyper=warn` when unset. The `log_level` field in `config.json` was effectively ignored, even though the UI form has a combobox that writes to it. The CLI binary (`mhrv-rs`) read `config.log_level` correctly via `init_logging()`; only the UI binary was broken. New precedence: `RUST_LOG` (explicit override) > `config.log_level` (what the user picked in the form) > `info,hyper=warn` (default). The Save button now also reinstalls the filter live via a `tracing_subscriber::reload::Handle`, so users don't need to restart for a level change to take effect. RUST_LOG still wins if set at boot — explicit override beats config in both directions. +• Soften the v1.8.1 decoy detection error message — enumerate four candidate causes instead of asserting AUTH_KEY mismatch ([#404](https://github.com/therealaleph/MasterHttpRelayVPN-RUST/issues/404)): @w0l4i reported the same `script_id` mixing decoy ERROR with successful batches inside a one-minute window — which rules out AUTH_KEY mismatch as the cause (a real mismatch fails 100% of batches against that deployment, never succeeds intermittently). Investigation showed the body string `"The script completed but did not return anything"` is **not** unique to our v1.8.0 bad-auth path — Apps Script itself returns the same body in three other unrelated cases: (2) Apps Script execution timeout or per-100s quota tear, (3) Google-side internal runtime hiccup, (4) ISP-side response truncation mid-flight (the #313 pattern). The v1.8.1 error message was a false positive in scenarios 2-4. The v1.8.2 message now reads: "got the v1.8.0 decoy/placeholder body — could be (1) AUTH_KEY mismatch (run a direct curl probe against the deployment to verify), (2) Apps Script execution timeout or per-100s quota tear (try lowering parallel_concurrency), (3) Apps Script internal hiccup (transient, retry next batch), or (4) ISP-side response truncation (#313 pattern, try a different google_ip). To distinguish (1) from the rest: set DIAGNOSTIC_MODE=true at the top of Code.gs + redeploy as new version — only AUTH_KEY mismatch returns this body in diagnostic mode." Users now have an actionable narrowing procedure instead of a confidently-wrong assertion. diff --git a/src/bin/ui.rs b/src/bin/ui.rs index 67695a8..7eb6328 100644 --- a/src/bin/ui.rs +++ b/src/bin/ui.rs @@ -33,16 +33,29 @@ fn main() -> eframe::Result<()> { let shared = Arc::new(Shared::default()); let (cmd_tx, cmd_rx) = std::sync::mpsc::channel::(); + // Load the user's saved form first so we can seed the tracing filter + // with their saved log level. Otherwise the form's log-level combobox + // would only ever take effect via env var or after Save → restart, and + // users on the UI binary (issue #401) reasonably expect the saved + // config.json `log_level` to apply at boot like it does for the CLI. + let (form, load_err) = load_form(); + let initial_toast = load_err.map(|e| (e, Instant::now())); + // Hook tracing events into the Recent log panel. Without this every // tracing::info! / debug! / trace! the proxy emits gets swallowed and // the panel only ever shows our manual push_log calls, making the log // level selector look useless (issue #12 bug 2). // - // The env-filter respects RUST_LOG if set, otherwise defaults to info - // so users see routing decisions immediately without any knob-turning. - // When they start the proxy and Save the config, the log level from the - // config is applied to the in-process filter (see on_start below). - install_ui_tracing(shared.clone()); + // Filter precedence (issue #401 fix in v1.8.2): + // 1. RUST_LOG env var if set — explicit override + // 2. Saved config's `log_level` (passed from form) — what users mean + // when they pick a level in the UI + // 3. "info,hyper=warn" — sensible default + // + // Save inside the running UI also installs the new filter via the + // reload handle (see `LOG_RELOAD` below), so users don't need to + // restart for a config change to take effect. + install_ui_tracing(shared.clone(), &form.log_level); let shared_bg = shared.clone(); std::thread::Builder::new() @@ -50,9 +63,6 @@ fn main() -> eframe::Result<()> { .spawn(move || background_thread(shared_bg, cmd_rx)) .expect("failed to spawn background thread"); - let (form, load_err) = load_form(); - let initial_toast = load_err.map(|e| (e, Instant::now())); - // Pick the renderer. Default is `glow` (OpenGL 2+) because that's // what we shipped through v1.0.x and it has the least binary-size // overhead. Users on older Windows boxes / RDP sessions / headless @@ -993,7 +1003,12 @@ impl eframe::App for App { ui.horizontal(|ui| { if ui.add(primary_button("Save config")).clicked() { match self.form.to_config().and_then(|c| save_config(&c)) { - Ok(p) => self.toast = Some((format!("Saved to {}", p.display()), Instant::now())), + Ok(p) => { + // Apply the new log level live so users don't have to + // restart for the combobox to take effect (#401). + apply_log_level(&self.form.log_level); + self.toast = Some((format!("Saved to {}", p.display()), Instant::now())); + } Err(e) => self.toast = Some((format!("Save failed: {}", e), Instant::now())), } } @@ -2193,14 +2208,19 @@ fn background_thread(shared: Arc, rx: Receiver) { /// Install a tracing subscriber that mirrors every log event into the UI's /// Recent log panel. /// -/// Respects `RUST_LOG` if set. Otherwise defaults to `info` — which is what -/// users mean when they pick a non-default log level in the form. (trace / -/// debug flip too much noise for a local GUI, so the combo-box changes level -/// live via the `reload` handle that `with_env_filter` gives us but we keep -/// the default boot-time level at info so first-run behavior is sensible.) -fn install_ui_tracing(shared: Arc) { +/// Filter precedence (issue #401, v1.8.2): +/// 1. `RUST_LOG` env var, if set +/// 2. The saved form's `log_level` (passed in from the loaded config) +/// 3. `info,hyper=warn` as a sensible default +/// +/// The constructed filter is wrapped in a `reload::Layer` and the handle +/// is stashed in `LOG_RELOAD` so that a Save inside the running UI can +/// reinstall the filter without a restart. See `apply_log_level`. +fn install_ui_tracing(shared: Arc, config_level: &str) { use tracing_subscriber::fmt::MakeWriter; - use tracing_subscriber::EnvFilter; + use tracing_subscriber::layer::SubscriberExt; + use tracing_subscriber::util::SubscriberInitExt; + use tracing_subscriber::{reload, EnvFilter}; /// A MakeWriter that pushes each line into the shared log panel. struct UiLogWriter { @@ -2254,19 +2274,71 @@ fn install_ui_tracing(shared: Arc) { } } - let filter = - EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("info,hyper=warn")); + // RUST_LOG > config.log_level > "info,hyper=warn" + let filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| { + let trimmed = config_level.trim(); + if trimmed.is_empty() { + EnvFilter::new("info,hyper=warn") + } else { + EnvFilter::try_new(trimmed).unwrap_or_else(|_| EnvFilter::new("info,hyper=warn")) + } + }); + + let (filter_layer, reload_handle) = reload::Layer::new(filter); + if LOG_RELOAD.set(reload_handle).is_err() { + // Already initialized — install_ui_tracing got called twice. Bail + // silently rather than panic; the existing subscriber stays live. + return; + } let writer = UiLogWriter { shared }; - let _ = tracing_subscriber::fmt() - .with_env_filter(filter) + let fmt_layer = tracing_subscriber::fmt::layer() .with_target(false) .with_ansi(false) - .with_writer(writer) + .with_writer(writer); + + let _ = tracing_subscriber::registry() + .with(filter_layer) + .with(fmt_layer) .try_init(); } +/// Reload handle for the UI's tracing EnvFilter — populated once at startup +/// by `install_ui_tracing`. `apply_log_level` uses it to swap in a new +/// filter when the user clicks Save with a different log level (#401). +static LOG_RELOAD: std::sync::OnceLock< + tracing_subscriber::reload::Handle< + tracing_subscriber::EnvFilter, + tracing_subscriber::Registry, + >, +> = std::sync::OnceLock::new(); + +/// Reinstall the tracing filter at runtime. Called from the Save handler +/// so the user's new `log_level` takes effect without a restart. RUST_LOG +/// still wins if it was set at process start — explicit override beats +/// config in both directions. +fn apply_log_level(level: &str) { + use tracing_subscriber::EnvFilter; + let Some(handle) = LOG_RELOAD.get() else { + return; + }; + if std::env::var_os("RUST_LOG").is_some() { + // RUST_LOG was set explicitly at boot — don't silently override. + return; + } + let trimmed = level.trim(); + let new = if trimmed.is_empty() { + EnvFilter::new("info,hyper=warn") + } else { + match EnvFilter::try_new(trimmed) { + Ok(f) => f, + Err(_) => return, + } + }; + let _ = handle.modify(|f| *f = new); +} + /// Where we drop downloaded release assets. Prefer the OS user Downloads /// dir (via the directories crate that's already in our tree), fall back /// to the user-data dir for platforms that don't expose one (edge case). diff --git a/src/tunnel_client.rs b/src/tunnel_client.rs index 5802ab0..d97caf1 100644 --- a/src/tunnel_client.rs +++ b/src/tunnel_client.rs @@ -881,24 +881,36 @@ async fn fire_batch( } let err_msg = format!("{}", e); let sid_short = &script_id[..script_id.len().min(8)]; - // Detect the v1.8.0 bad-auth decoy HTML body. The relay layer - // wraps any non-JSON response in `BadResponse("no json in - // batch response: ")`. The decoy body string - // `"The script completed but did not return anything"` is - // distinctive — Apps Script's stock pages never include it, - // and our own `Code.gs` only returns it when AUTH_KEY check - // fails. Surfacing this as an actionable hint saves users - // (and #404 / #310 sina-b4hrm class issues) hours of - // staring at "no json in batch response". + // Detect the body string we ship as the v1.8.0 bad-auth + // decoy. v1.8.1 asserted "AUTH_KEY mismatch" outright, but + // #404 (w0l4i) found the same body comes back from Apps + // Script in 3 other unrelated cases too: + // + // 1. AUTH_KEY mismatch — our intentional decoy + // 2. Apps Script execution timeout/ — runtime hit 6-min + // mid-call quota tear cap or per-100s quota + // 3. Apps Script internal hiccup — Google-side flake, + // serves placeholder + // 4. ISP-side response truncation — #313 pattern, the + // response was assembled + // but ate an RST mid-flight + // + // So we surface all four candidates instead of asserting #1. + // Users can flip DIAGNOSTIC_MODE=true in Code.gs to disambiguate: + // only #1 still returns the decoy in diagnostic mode; the + // others return real JSON or different errors. if err_msg.contains("The script completed but did not return anything") { tracing::error!( - "batch failed (script {}): got the v1.8.0 bad-auth decoy — \ - your AUTH_KEY in mhrv-rs config does NOT match the AUTH_KEY \ - in this deployment's Code.gs. Either fix the mismatch + \ - redeploy as a NEW VERSION (Apps Script doesn't auto-pick-up \ - AUTH_KEY edits without an explicit redeploy), or set \ - DIAGNOSTIC_MODE=true at the top of Code.gs + redeploy to \ - see the explicit JSON `unauthorized` error during setup.", + "batch failed (script {}): got the v1.8.0 decoy/placeholder body — \ + could be (1) AUTH_KEY mismatch between mhrv-rs config and Code.gs \ + (run a direct curl probe against the deployment to verify), \ + (2) Apps Script execution timeout or per-100s quota tear (try \ + lowering parallel_concurrency in config), (3) Apps Script \ + internal hiccup (transient, retry next batch), or (4) ISP-side \ + response truncation (#313 pattern, try a different google_ip). \ + To distinguish (1) from the rest: set DIAGNOSTIC_MODE=true at \ + the top of Code.gs + redeploy as new version — only AUTH_KEY \ + mismatch returns this body in diagnostic mode.", sid_short ); } else {