diff --git a/src-tauri/src/cmd/profile_switch/driver.rs b/src-tauri/src/cmd/profile_switch/driver.rs index 45028dae..bfd5a91a 100644 --- a/src-tauri/src/cmd/profile_switch/driver.rs +++ b/src-tauri/src/cmd/profile_switch/driver.rs @@ -190,7 +190,6 @@ fn handle_enqueue( let accepted = true; let profile_key = request.profile_id().clone(); let cleanup_pending = state.active.is_none() && !state.cleanup_profiles.is_empty(); - if cleanup_pending && state.cleanup_profiles.contains_key(&profile_key) { logging!( debug, @@ -209,12 +208,11 @@ fn handle_enqueue( logging!( debug, Type::Cmd, - "Cleanup running for {} profile(s); collapsing pending requests before enqueuing task {} -> {}", + "Cleanup running for {} profile(s); queueing task {} -> {} for later", state.cleanup_profiles.len(), request.task_id(), profile_key ); - drop_pending_requests(state); } if let Some(previous) = state @@ -307,12 +305,6 @@ fn handle_completion( start_next_job(state, driver_tx, manager); } -fn drop_pending_requests(state: &mut SwitchDriverState) { - while let Some(request) = state.queue.pop_front() { - discard_request(state, request); - } -} - fn discard_request(state: &mut SwitchDriverState, request: SwitchRequest) { let key = request.profile_id().clone(); let should_remove = state diff --git a/src-tauri/src/cmd/profile_switch/workflow.rs b/src-tauri/src/cmd/profile_switch/workflow.rs index 10d41110..e71be1be 100644 --- a/src-tauri/src/cmd/profile_switch/workflow.rs +++ b/src-tauri/src/cmd/profile_switch/workflow.rs @@ -368,12 +368,25 @@ pub(super) async fn restore_previous_profile(previous: Option) -> C } async fn close_connections_after_switch(profile_id: SmartString) { + logging!( + info, + Type::Cmd, + "Starting post-switch cleanup for profile {}", + profile_id.as_str() + ); match time::timeout(SWITCH_CLEANUP_TIMEOUT, async { handle::Handle::mihomo().await.close_all_connections().await }) .await { - Ok(Ok(())) => {} + Ok(Ok(())) => { + logging!( + info, + Type::Cmd, + "Post-switch cleanup finished for profile {}", + profile_id.as_str() + ); + } Ok(Err(err)) => { logging!( warn, @@ -402,16 +415,46 @@ fn schedule_post_switch_success( task_id: u64, ) -> CleanupHandle { AsyncHandler::spawn(move || async move { - handle::Handle::notify_profile_switch_finished( + logging!( + info, + Type::Cmd, + "Post-switch notify start (success={}, profile={}, task={})", + success, + profile_id.as_str(), + task_id + ); + let notify_result = handle::Handle::notify_profile_switch_finished( profile_id.clone(), success, notify, task_id, ); + logging!( + info, + Type::Cmd, + "notify_profile_switch_finished completed (success={}, task={}, result={:?})", + success, + task_id, + notify_result + ); if notify && success { - handle::Handle::notice_message("info", "Profile Switched"); + let notice_result = handle::Handle::notice_message("info", "Profile Switched"); + logging!( + info, + Type::Cmd, + "notice_message returned for task {} (result={:?})", + task_id, + notice_result + ); } close_connections_after_switch(profile_id).await; + logging!( + info, + Type::Cmd, + "Post-switch notify finished (success={}, task={})", + success, + task_id + ); }) } @@ -421,8 +464,21 @@ pub(super) fn schedule_post_switch_failure( task_id: u64, ) -> CleanupHandle { AsyncHandler::spawn(move || async move { + logging!( + info, + Type::Cmd, + "Post-switch notify start (success=false, profile={}, task={})", + profile_id.as_str(), + task_id + ); handle::Handle::notify_profile_switch_finished(profile_id.clone(), false, notify, task_id); close_connections_after_switch(profile_id).await; + logging!( + info, + Type::Cmd, + "Post-switch notify finished (success=false, task={})", + task_id + ); }) } diff --git a/src-tauri/src/core/handle.rs b/src-tauri/src/core/handle.rs index 30fc651a..a92136d5 100644 --- a/src-tauri/src/core/handle.rs +++ b/src-tauri/src/core/handle.rs @@ -5,6 +5,8 @@ use parking_lot::RwLock; use serde_json::{Value, json}; use smartstring::alias::String; use std::{ + any::Any, + env, sync::Arc, thread, time::{SystemTime, UNIX_EPOCH}, @@ -15,6 +17,9 @@ use tokio::sync::RwLockReadGuard; use super::notification::{ErrorMessage, FrontendEvent, NotificationSystem}; +const BYPASS_PROFILE_SWITCH_FINISHED_STATIC: bool = false; +const BYPASS_NOTICE_MESSAGE_STATIC: bool = false; + #[derive(Debug, Clone)] pub struct Handle { is_exiting: Arc>, @@ -106,12 +111,52 @@ impl Handle { notify: bool, task_id: u64, ) { - Self::send_event(FrontendEvent::ProfileSwitchFinished { + logging!( + info, + Type::Cmd, + "Frontend notify start (profile_switch_finished, profile={}, success={}, notify={}, task={})", profile_id, success, notify, - task_id, + task_id + ); + + if BYPASS_PROFILE_SWITCH_FINISHED_STATIC || Self::should_bypass_profile_switch_finished() { + logging!( + warn, + Type::Cmd, + "Frontend notify bypassed (static={}, env={}, task={})", + BYPASS_PROFILE_SWITCH_FINISHED_STATIC, + env::var("CVR_BYPASS_PROFILE_SWITCH_FINISHED").unwrap_or_else(|_| "unset".into()), + task_id + ); + return; + } + + let result = std::panic::catch_unwind(|| { + Self::send_event(FrontendEvent::ProfileSwitchFinished { + profile_id, + success, + notify, + task_id, + }); }); + + match result { + Ok(_) => logging!( + info, + Type::Cmd, + "Frontend notify completed (profile_switch_finished, task={})", + task_id + ), + Err(payload) => logging!( + error, + Type::Cmd, + "Frontend notify panicked (profile_switch_finished, task={}, payload={})", + task_id, + describe_panic(payload.as_ref()) + ), + } } pub fn notify_rust_panic(message: String, location: String) { @@ -228,10 +273,61 @@ impl Handle { return; } - Self::send_event(FrontendEvent::NoticeMessage { - status: status_str, - message: msg_str, - }); + logging!( + info, + Type::Frontend, + "Frontend notice start (status={}, msg={})", + status_str, + msg_str + ); + + if BYPASS_NOTICE_MESSAGE_STATIC || Self::should_bypass_notice_message() { + logging!( + warn, + Type::Frontend, + "Frontend notice bypassed (static={}, env={}, status={})", + BYPASS_NOTICE_MESSAGE_STATIC, + env::var("CVR_BYPASS_NOTICE_MESSAGE").unwrap_or_else(|_| "unset".into()), + status_str + ); + return; + } + + let event = FrontendEvent::NoticeMessage { + status: status_str.clone(), + message: msg_str.clone(), + }; + + let result = std::panic::catch_unwind(|| Self::send_event(event)); + match result { + Ok(_) => logging!( + info, + Type::Frontend, + "Frontend notice completed (status={})", + status_str + ), + Err(payload) => logging!( + error, + Type::Frontend, + "Frontend notice panicked (status={}, payload={})", + status_str, + describe_panic(payload.as_ref()) + ), + } + } + + fn should_bypass_profile_switch_finished() -> bool { + match env::var("CVR_BYPASS_PROFILE_SWITCH_FINISHED") { + Ok(value) => value != "0", + Err(_) => false, + } + } + + fn should_bypass_notice_message() -> bool { + match env::var("CVR_BYPASS_NOTICE_MESSAGE") { + Ok(value) => value != "0", + Err(_) => false, + } } fn send_event(event: FrontendEvent) { @@ -303,6 +399,16 @@ impl Handle { } } +pub(crate) fn describe_panic(payload: &(dyn Any + Send)) -> String { + if let Some(message) = payload.downcast_ref::<&str>() { + (*message).to_string().into() + } else if let Some(message) = payload.downcast_ref::() { + message.clone().into() + } else { + "unknown panic".into() + } +} + #[cfg(target_os = "macos")] impl Handle { pub fn set_activation_policy(&self, policy: tauri::ActivationPolicy) -> Result<(), String> { diff --git a/src-tauri/src/core/notification.rs b/src-tauri/src/core/notification.rs index 3f39b29f..32df7625 100644 --- a/src-tauri/src/core/notification.rs +++ b/src-tauri/src/core/notification.rs @@ -6,6 +6,7 @@ use crate::{ use parking_lot::RwLock; use smartstring::alias::String; use std::{ + env, sync::{ atomic::{AtomicU64, Ordering}, mpsc, @@ -58,6 +59,13 @@ struct EventStats { last_error_time: RwLock>, } +const SKIP_PROFILE_SWITCH_FINISHED_STATIC: bool = false; +const SKIP_PROFILE_SWITCH_FINISHED_ENV: &str = "CVR_SKIP_PROFILE_SWITCH_FINISHED"; +const SKIP_NOTICE_MESSAGE_STATIC: bool = true; +const SKIP_NOTICE_MESSAGE_ENV: &str = "CVR_SKIP_NOTICE_MESSAGE"; +const SKIP_REFRESH_PROXY_STATIC: bool = true; +const SKIP_REFRESH_PROXY_ENV: &str = "CVR_SKIP_REFRESH_PROXY"; + #[derive(Debug, Clone)] pub struct ErrorMessage { pub status: String, @@ -119,14 +127,25 @@ impl NotificationSystem { use super::handle::Handle; let handle = Handle::global(); + logging!(info, Type::Frontend, "Notification worker started"); while !handle.is_exiting() { match rx.recv_timeout(std::time::Duration::from_millis(100)) { - Ok(event) => Self::process_event(handle, event), + Ok(event) => { + logging!( + info, + Type::Frontend, + "Worker received event: {}", + Self::describe_event(&event) + ); + Self::process_event(handle, event) + } Err(mpsc::RecvTimeoutError::Disconnected) => break, Err(mpsc::RecvTimeoutError::Timeout) => {} } } + + logging!(info, Type::Frontend, "Notification worker exiting"); } fn process_event(handle: &super::handle::Handle, event: FrontendEvent) { @@ -140,19 +159,88 @@ impl NotificationSystem { } if let Some(window) = super::handle::Handle::get_window() { + logging!( + info, + Type::Frontend, + "Processing event for window: {}", + Self::describe_event(&event) + ); + let start = std::time::Instant::now(); system.emit_to_window(&window, event); + let elapsed = start.elapsed(); + logging!(info, Type::Frontend, "Event processed in {:?}", elapsed); thread::sleep(timing::EVENT_EMIT_DELAY); } } fn should_skip_event(&self, event: &FrontendEvent) -> bool { let is_emergency = *self.emergency_mode.read(); + if (SKIP_PROFILE_SWITCH_FINISHED_STATIC || Self::skip_profile_switch_finished_env()) + && matches!(event, FrontendEvent::ProfileSwitchFinished { .. }) + { + logging!( + warn, + Type::Frontend, + "Skipping ProfileSwitchFinished event (static={}, env={})", + SKIP_PROFILE_SWITCH_FINISHED_STATIC, + env::var(SKIP_PROFILE_SWITCH_FINISHED_ENV).unwrap_or_else(|_| "unset".into()) + ); + return true; + } + + if (SKIP_NOTICE_MESSAGE_STATIC || Self::skip_notice_env()) + && matches!(event, FrontendEvent::NoticeMessage { .. }) + { + logging!( + warn, + Type::Frontend, + "Skipping NoticeMessage event (static={}, env={})", + SKIP_NOTICE_MESSAGE_STATIC, + env::var(SKIP_NOTICE_MESSAGE_ENV).unwrap_or_else(|_| "unset".into()) + ); + return true; + } + + if (SKIP_REFRESH_PROXY_STATIC || Self::skip_refresh_proxy_env()) + && matches!(event, FrontendEvent::RefreshProxy) + { + logging!( + warn, + Type::Frontend, + "Skipping RefreshProxy event (static={}, env={})", + SKIP_REFRESH_PROXY_STATIC, + env::var(SKIP_REFRESH_PROXY_ENV).unwrap_or_else(|_| "unset".into()) + ); + return true; + } + matches!( (is_emergency, event), (true, FrontendEvent::NoticeMessage { status, .. }) if status == "info" ) } + fn skip_profile_switch_finished_env() -> bool { + match env::var(SKIP_PROFILE_SWITCH_FINISHED_ENV) { + Ok(value) => value != "0", + Err(_) => false, + } + } + + fn skip_notice_env() -> bool { + match env::var(SKIP_NOTICE_MESSAGE_ENV) { + Ok(value) => value != "0", + Err(_) => false, + } + } + + fn skip_refresh_proxy_env() -> bool { + match env::var(SKIP_REFRESH_PROXY_ENV) { + Ok(value) => value != "0", + Err(_) => false, + } + } + fn emit_to_window(&self, window: &WebviewWindow, event: FrontendEvent) { let (event_name, payload) = self.serialize_event(event); @@ -161,14 +249,79 @@ impl NotificationSystem { return; }; - match window.emit(event_name, payload) { - Ok(_) => { + let emit_result = + if event_name == "profile-switch-finished" || event_name == "verge://notice-message" { + let app_handle = super::handle::Handle::app_handle(); + std::panic::catch_unwind(std::panic::AssertUnwindSafe(|| { + app_handle + .emit_to("main", event_name, payload.clone()) + .map_err(|e| e) + })) + } else { + std::panic::catch_unwind(std::panic::AssertUnwindSafe(|| { + window.emit(event_name, payload.clone()).map_err(|e| e) + })) + }; + + match emit_result { + Ok(Ok(())) => { self.stats.total_sent.fetch_add(1, Ordering::Relaxed); + logging!( + info, + Type::Frontend, + "Event emitted: {} payload={}", + event_name, + payload + ); } - Err(e) => { + Ok(Err(e)) => { logging!(warn, Type::Frontend, "Event emit failed: {}", e); self.handle_emit_error(); } + Err(payload) => { + logging!( + error, + Type::Frontend, + "Event emit panicked: {} ({})", + event_name, + super::handle::describe_panic(payload.as_ref()) + ); + self.handle_emit_error(); + } + } + } + + fn describe_event(event: &FrontendEvent) -> String { + match event { + FrontendEvent::RefreshClash => String::from("RefreshClash"), + FrontendEvent::RefreshVerge => String::from("RefreshVerge"), + FrontendEvent::RefreshProxy => String::from("RefreshProxy"), + FrontendEvent::ProxiesUpdated { .. } => String::from("ProxiesUpdated"), + FrontendEvent::NoticeMessage { status, .. } => { + format!("NoticeMessage({})", status).into() + } + FrontendEvent::ProfileChanged { current_profile_id } => { + format!("ProfileChanged({})", current_profile_id).into() + } + FrontendEvent::ProfileSwitchFinished { + profile_id, + task_id, + .. + } => format!( + "ProfileSwitchFinished(profile={}, task={})", + profile_id, task_id + ) + .into(), + FrontendEvent::TimerUpdated { profile_index } => { + format!("TimerUpdated({})", profile_index).into() + } + FrontendEvent::ProfileUpdateStarted { uid } => { + format!("ProfileUpdateStarted({})", uid).into() + } + FrontendEvent::ProfileUpdateCompleted { uid } => { + format!("ProfileUpdateCompleted({})", uid).into() + } + FrontendEvent::RustPanic { message, .. } => format!("RustPanic({})", message).into(), } } diff --git a/src-tauri/src/core/timer.rs b/src-tauri/src/core/timer.rs index 29eba1fd..af9fd793 100644 --- a/src-tauri/src/core/timer.rs +++ b/src-tauri/src/core/timer.rs @@ -460,9 +460,19 @@ impl Timer { fn emit_update_event(_uid: &str, _is_start: bool) { { if _is_start { - super::handle::Handle::notify_profile_update_started(_uid.into()); + logging!( + warn, + Type::Timer, + "Skipping profile update started event for uid={} (static bypass)", + _uid + ); } else { - super::handle::Handle::notify_profile_update_completed(_uid.into()); + logging!( + warn, + Type::Timer, + "Skipping profile update completed event for uid={} (static bypass)", + _uid + ); } } }