diff --git a/Cargo.lock b/Cargo.lock index 92da630..f79a2ea 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2793,7 +2793,7 @@ checksum = "7b2093cf4c8eb1e67749a6762251bc9cd836b6fc171623bd0a9d324d37af2417" [[package]] name = "telemt" -version = "3.3.30" +version = "3.3.31" dependencies = [ "aes", "anyhow", diff --git a/Cargo.toml b/Cargo.toml index 80ca1b2..42173ca 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "telemt" -version = "3.3.30" +version = "3.3.31" edition = "2024" [profile.release] diff --git a/src/proxy/handshake.rs b/src/proxy/handshake.rs index 2ef8e1b..fbaffa2 100644 --- a/src/proxy/handshake.rs +++ b/src/proxy/handshake.rs @@ -13,7 +13,7 @@ use std::sync::Arc; use std::sync::{Mutex, OnceLock}; use std::time::{Duration, Instant}; use tokio::io::{AsyncRead, AsyncWrite, AsyncWriteExt}; -use tracing::{debug, trace, warn}; +use tracing::{debug, info, trace, warn}; use zeroize::{Zeroize, Zeroizing}; use crate::config::{ProxyConfig, UnknownSniAction}; @@ -28,6 +28,8 @@ use rand::RngExt; const ACCESS_SECRET_BYTES: usize = 16; static INVALID_SECRET_WARNED: OnceLock>> = OnceLock::new(); +const UNKNOWN_SNI_WARN_COOLDOWN_SECS: u64 = 5; +static UNKNOWN_SNI_WARN_NEXT_ALLOWED: OnceLock>> = OnceLock::new(); #[cfg(test)] const WARNED_SECRET_MAX_ENTRIES: usize = 64; #[cfg(not(test))] @@ -86,6 +88,24 @@ fn auth_probe_saturation_state_lock() .unwrap_or_else(|poisoned| poisoned.into_inner()) } +fn unknown_sni_warn_state_lock() -> std::sync::MutexGuard<'static, Option> { + UNKNOWN_SNI_WARN_NEXT_ALLOWED + .get_or_init(|| Mutex::new(None)) + .lock() + .unwrap_or_else(|poisoned| poisoned.into_inner()) +} + +fn should_emit_unknown_sni_warn(now: Instant) -> bool { + let mut guard = unknown_sni_warn_state_lock(); + if let Some(next_allowed) = *guard + && now < next_allowed + { + return false; + } + *guard = Some(now + Duration::from_secs(UNKNOWN_SNI_WARN_COOLDOWN_SECS)); + true +} + fn normalize_auth_probe_ip(peer_ip: IpAddr) -> IpAddr { match peer_ip { IpAddr::V4(ip) => IpAddr::V4(ip), @@ -412,6 +432,25 @@ fn auth_probe_test_lock() -> &'static Mutex<()> { TEST_LOCK.get_or_init(|| Mutex::new(())) } +#[cfg(test)] +fn unknown_sni_warn_test_lock() -> &'static Mutex<()> { + static TEST_LOCK: OnceLock> = OnceLock::new(); + TEST_LOCK.get_or_init(|| Mutex::new(())) +} + +#[cfg(test)] +fn clear_unknown_sni_warn_state_for_testing() { + if UNKNOWN_SNI_WARN_NEXT_ALLOWED.get().is_some() { + let mut guard = unknown_sni_warn_state_lock(); + *guard = None; + } +} + +#[cfg(test)] +fn should_emit_unknown_sni_warn_for_testing(now: Instant) -> bool { + should_emit_unknown_sni_warn(now) +} + #[cfg(test)] fn clear_warned_secrets_for_testing() { if let Some(warned) = INVALID_SECRET_WARNED.get() @@ -658,12 +697,25 @@ where if client_sni.is_some() && matched_tls_domain.is_none() && preferred_user_hint.is_none() { auth_probe_record_failure(peer.ip(), Instant::now()); maybe_apply_server_hello_delay(config).await; - debug!( - peer = %peer, - sni = ?client_sni, - action = ?config.censorship.unknown_sni_action, - "TLS handshake rejected by unknown SNI policy" - ); + let sni = client_sni.as_deref().unwrap_or_default(); + let log_now = Instant::now(); + if should_emit_unknown_sni_warn(log_now) { + warn!( + peer = %peer, + sni = %sni, + unknown_sni = true, + unknown_sni_action = ?config.censorship.unknown_sni_action, + "TLS handshake rejected by unknown SNI policy" + ); + } else { + info!( + peer = %peer, + sni = %sni, + unknown_sni = true, + unknown_sni_action = ?config.censorship.unknown_sni_action, + "TLS handshake rejected by unknown SNI policy" + ); + } return match config.censorship.unknown_sni_action { UnknownSniAction::Drop => HandshakeResult::Error(ProxyError::UnknownTlsSni), UnknownSniAction::Mask => HandshakeResult::BadClient { reader, writer }, diff --git a/src/proxy/tests/handshake_security_tests.rs b/src/proxy/tests/handshake_security_tests.rs index 6796c5c..0e43d35 100644 --- a/src/proxy/tests/handshake_security_tests.rs +++ b/src/proxy/tests/handshake_security_tests.rs @@ -1643,6 +1643,32 @@ fn auth_probe_capacity_fresh_full_map_still_tracks_newcomer_with_bounded_evictio ); } +#[test] +fn unknown_sni_warn_cooldown_first_event_is_warn_and_repeated_events_are_info_until_window_expires() +{ + let _guard = unknown_sni_warn_test_lock() + .lock() + .unwrap_or_else(|poisoned| poisoned.into_inner()); + clear_unknown_sni_warn_state_for_testing(); + + let now = Instant::now(); + + assert!( + should_emit_unknown_sni_warn_for_testing(now), + "first unknown SNI event must be eligible for WARN emission" + ); + assert!( + !should_emit_unknown_sni_warn_for_testing(now + Duration::from_secs(1)), + "events inside cooldown window must be demoted from WARN to INFO" + ); + assert!( + should_emit_unknown_sni_warn_for_testing( + now + Duration::from_secs(UNKNOWN_SNI_WARN_COOLDOWN_SECS) + ), + "once cooldown expires, next unknown SNI event must be WARN-eligible again" + ); +} + #[test] fn stress_auth_probe_full_map_churn_keeps_bound_and_tracks_newcomers() { let _guard = auth_probe_test_lock()