feat: v1.8.2 — UI tracing reads config.log_level + softer decoy detection

- src/bin/ui.rs: install_ui_tracing now takes config_level. Filter
  precedence is RUST_LOG > config.log_level > info,hyper=warn. The
  filter is wrapped in a reload::Layer; Save reinstalls it via
  apply_log_level so users don't need to restart for a level change.
  Fixes #401 (w0l4i) — config.log_level was previously dead on the
  UI binary even though the CLI honored it via init_logging.

- src/tunnel_client.rs: v1.8.1 asserted "AUTH_KEY mismatch" on the
  Apps Script placeholder body, but #404 (w0l4i) showed mixed
  success/failure on the same script_id, which rules that out. The
  body is also returned for Apps Script execution timeout, quota
  tear, internal hiccup, and ISP-side truncation. Error message now
  enumerates all four candidates and points to DIAGNOSTIC_MODE for
  disambiguation.
This commit is contained in:
therealaleph
2026-04-28 15:06:58 +03:00
parent fd865dfe9f
commit d8170286fa
5 changed files with 129 additions and 39 deletions
Generated
+1 -1
View File
@@ -2222,7 +2222,7 @@ dependencies = [
[[package]]
name = "mhrv-rs"
version = "1.8.1"
version = "1.8.2"
dependencies = [
"base64 0.22.1",
"bytes",
+1 -1
View File
@@ -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"
+6
View File
@@ -0,0 +1,6 @@
<!-- see docs/changelog/v1.1.0.md for the file format: Persian, then `---`, then English. -->
• اصلاح 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.
+93 -21
View File
@@ -33,16 +33,29 @@ fn main() -> eframe::Result<()> {
let shared = Arc::new(Shared::default());
let (cmd_tx, cmd_rx) = std::sync::mpsc::channel::<Cmd>();
// 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<Shared>, rx: Receiver<Cmd>) {
/// 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<Shared>) {
/// 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<Shared>, 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<Shared>) {
}
}
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).
+28 -16
View File
@@ -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: <body prefix>")`. 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 {