feat(server): log reasons for dropped packets

This commit is contained in:
ospab 2026-06-19 19:14:46 +03:00
parent 6eb7b369a0
commit fc339b3643
4 changed files with 59 additions and 42 deletions

View File

@ -84,31 +84,33 @@ pub async fn dial_tcp(
let target_host_str = target_host.to_string(); let target_host_str = target_host.to_string();
// Spawn bridge task let server_str = server.to_string();
tokio::spawn(async move {
// Send initial handshake
if let Ok(action) = machine.on_event(OstpEvent::Start) {
handle_action(action, &transport, &mut server_stream).await;
}
// Wait for handshake response (server sends HandshakePayload back) // Spawn bridge task
let mut buf = [0u8; 8192]; tokio::spawn(async move {
let mut handshake_success = false; // Send initial handshake
match tokio::time::timeout( if let Ok(action) = machine.on_event(OstpEvent::Start) {
std::time::Duration::from_millis(3000), handle_action(action, &transport, &mut server_stream).await;
transport.recv(&mut buf), }
).await {
Ok(Ok(n)) => { // Wait for handshake response (server sends HandshakePayload back)
if let Ok(action) = machine.on_event(OstpEvent::Inbound(bytes::Bytes::copy_from_slice(&buf[..n]))) { let mut buf = [0u8; 8192];
handle_action(action, &transport, &mut server_stream).await; let mut handshake_success = false;
handshake_success = true; match tokio::time::timeout(
std::time::Duration::from_millis(3000),
transport.recv(&mut buf),
).await {
Ok(Ok(n)) => {
if let Ok(action) = machine.on_event(OstpEvent::Inbound(bytes::Bytes::copy_from_slice(&buf[..n]))) {
handle_action(action, &transport, &mut server_stream).await;
handshake_success = true;
}
}
_ => {
tracing::warn!("TCP handshake timeout for {}:{}", server_str, port);
return;
} }
} }
_ => {
tracing::warn!("TCP handshake timeout for {}:{}", server, port);
return;
}
}
if !handshake_success { if !handshake_success {
tracing::warn!("TCP handshake failed or protocol machine error"); tracing::warn!("TCP handshake failed or protocol machine error");

View File

@ -12,7 +12,7 @@ use portable_atomic::AtomicU64;
// const MAX_SESSIONS removed because dynamic limit is used // const MAX_SESSIONS removed because dynamic limit is used
pub enum DispatchOutcome { pub enum DispatchOutcome {
Unauthorized, Unauthorized(String),
Accepted { Accepted {
responses: Vec<Bytes>, responses: Vec<Bytes>,
app_payloads: Vec<(u32, u16, Bytes)>, // session_id, stream_id, payload app_payloads: Vec<(u32, u16, Bytes)>, // session_id, stream_id, payload
@ -182,7 +182,7 @@ impl Dispatcher {
pub fn on_datagram(&mut self, peer: SocketAddr, packet: Bytes) -> Result<DispatchOutcome> { pub fn on_datagram(&mut self, peer: SocketAddr, packet: Bytes) -> Result<DispatchOutcome> {
if packet.len() < 4 { if packet.len() < 4 {
return Ok(DispatchOutcome::Unauthorized); return Ok(DispatchOutcome::Unauthorized("packet too short".to_string()));
} }
let mut session_id_opt = None; let mut session_id_opt = None;
@ -239,7 +239,7 @@ impl Dispatcher {
tracing::info!("Dropping session {} for key {} (valid={}, over_limit={})", tracing::info!("Dropping session {} for key {} (valid={}, over_limit={})",
session_id, access_key, key_valid, user_stats.is_over_limit()); session_id, access_key, key_valid, user_stats.is_over_limit());
self.drop_session(session_id); self.drop_session(session_id);
return Ok(DispatchOutcome::Unauthorized); return Ok(DispatchOutcome::Unauthorized("key invalid or over limit".to_string()));
} }
} }
@ -260,8 +260,7 @@ impl Dispatcher {
let action = match peer_state.machine.on_event(OstpEvent::Inbound(packet)) { let action = match peer_state.machine.on_event(OstpEvent::Inbound(packet)) {
Ok(a) => a, Ok(a) => a,
Err(e) => { Err(e) => {
tracing::warn!("Protocol error for session {}: {}", session_id, e); return Ok(DispatchOutcome::Unauthorized(format!("protocol error: {}", e)));
return Ok(DispatchOutcome::Unauthorized);
} }
}; };
@ -303,13 +302,17 @@ impl Dispatcher {
// Not an existing session — try each registered access key's derived obfuscation key // Not an existing session — try each registered access key's derived obfuscation key
let keys_snapshot: Vec<String> = self.access_keys.read().unwrap_or_else(|e| e.into_inner()).keys().cloned().collect(); let keys_snapshot: Vec<String> = self.access_keys.read().unwrap_or_else(|e| e.into_inner()).keys().cloned().collect();
let mut failed_trials = Vec::new();
for candidate_key in keys_snapshot { for candidate_key in keys_snapshot {
let secrets = ostp_core::crypto::derive_all_secrets(candidate_key.as_bytes()); let secrets = ostp_core::crypto::derive_all_secrets(candidate_key.as_bytes());
// Decode the session_id using this key's obfuscation // Decode the session_id using this key's obfuscation
// The handshake mask is derived from the Noise payload at bytes [6..], // The handshake mask is derived from the Noise payload at bytes [6..],
// so we must deobfuscate the full packet, not just the header. // so we must deobfuscate the full packet, not just the header.
if packet.len() < 7 { continue; } if packet.len() < 7 {
failed_trials.push(format!("key {}: packet too short", candidate_key));
continue;
}
let mut trial = packet.to_vec(); let mut trial = packet.to_vec();
ostp_core::crypto::deobfuscate_packet_inplace(&mut trial, &secrets.obfuscation_key, true); ostp_core::crypto::deobfuscate_packet_inplace(&mut trial, &secrets.obfuscation_key, true);
let candidate_session_id = u32::from_be_bytes([trial[0], trial[1], trial[2], trial[3]]); let candidate_session_id = u32::from_be_bytes([trial[0], trial[1], trial[2], trial[3]]);
@ -331,7 +334,10 @@ impl Dispatcher {
}; };
let action = match machine.on_event(OstpEvent::Inbound(packet.clone())) { let action = match machine.on_event(OstpEvent::Inbound(packet.clone())) {
Ok(a) => a, Ok(a) => a,
Err(_) => continue, Err(e) => {
failed_trials.push(format!("key {}: crypto err: {}", candidate_key, e));
continue;
}
}; };
if let ProtocolAction::HandshakePayload(payload, response_opt) = action { if let ProtocolAction::HandshakePayload(payload, response_opt) = action {
@ -345,6 +351,7 @@ impl Dispatcher {
let sid_from_payload = u32::from_be_bytes(sid_bytes); let sid_from_payload = u32::from_be_bytes(sid_bytes);
if sid_from_payload != candidate_session_id { if sid_from_payload != candidate_session_id {
failed_trials.push(format!("key {}: sid mismatch", candidate_key));
continue; continue;
} }
@ -352,6 +359,7 @@ impl Dispatcher {
if let Ok(key_from_payload) = std::str::from_utf8(key_bytes) { if let Ok(key_from_payload) = std::str::from_utf8(key_bytes) {
// The key embedded in the payload must match the candidate key we decoded with // The key embedded in the payload must match the candidate key we decoded with
if key_from_payload != candidate_key { if key_from_payload != candidate_key {
failed_trials.push(format!("key {}: embedded key mismatch", candidate_key));
continue; continue;
} }
@ -362,14 +370,16 @@ impl Dispatcher {
let drift = (now as i64 - ts as i64).abs(); let drift = (now as i64 - ts as i64).abs();
if drift > 300 { if drift > 300 {
tracing::warn!("Handshake rejected: timestamp drift {}s exceeds 300s limit (peer={})", drift, peer); let reason = format!("timestamp drift {}s exceeds 300s limit", drift);
tracing::warn!("Handshake rejected for {}: {}", peer, reason);
failed_trials.push(format!("key {}: {}", candidate_key, reason));
continue; continue;
} }
if !self.replay_cache.contains_key(&payload.to_vec()) { if !self.replay_cache.contains_key(&payload.to_vec()) {
if self.replay_cache.len() >= 50_000 { if self.replay_cache.len() >= 50_000 {
tracing::warn!("Replay cache full (100000 entries), rejecting handshake from {}", peer); tracing::warn!("Replay cache full (100000 entries), rejecting handshake from {}", peer);
return Ok(DispatchOutcome::Unauthorized); return Ok(DispatchOutcome::Unauthorized("replay cache full".to_string()));
} }
self.replay_cache.insert(payload.to_vec(), ts); self.replay_cache.insert(payload.to_vec(), ts);
@ -383,7 +393,7 @@ impl Dispatcher {
// Check traffic limit before accepting // Check traffic limit before accepting
if user_stats.is_over_limit() { if user_stats.is_over_limit() {
tracing::warn!("User {} exceeded traffic limit, rejecting handshake from {}", candidate_key, peer); tracing::warn!("User {} exceeded traffic limit, rejecting handshake from {}", candidate_key, peer);
return Ok(DispatchOutcome::Unauthorized); return Ok(DispatchOutcome::Unauthorized("user over traffic limit".to_string()));
} }
self.peer_machines.insert(candidate_session_id, PeerState { self.peer_machines.insert(candidate_session_id, PeerState {
@ -410,7 +420,13 @@ impl Dispatcher {
} }
} }
Ok(DispatchOutcome::Unauthorized) let reason = if failed_trials.is_empty() {
"no valid handshake payload found".to_string()
} else {
format!("all key trials failed: {}", failed_trials.join(", "))
};
Ok(DispatchOutcome::Unauthorized(reason))
} }
pub fn outbound_to_session(&mut self, session_id: u32, stream_id: u16, payload: Bytes) -> Result<Option<(Bytes, SocketAddr)>> { pub fn outbound_to_session(&mut self, session_id: u32, stream_id: u16, payload: Bytes) -> Result<Option<(Bytes, SocketAddr)>> {

View File

@ -45,7 +45,7 @@ pub(crate) enum UiEvent {
PeerSeen { peer: IpAddr }, PeerSeen { peer: IpAddr },
#[allow(dead_code)] Rx { peer: IpAddr, bytes: usize }, #[allow(dead_code)] Rx { peer: IpAddr, bytes: usize },
#[allow(dead_code)] Tx { peer: IpAddr, bytes: usize }, #[allow(dead_code)] Tx { peer: IpAddr, bytes: usize },
UnauthorizedProbe { peer: IpAddr, bytes: usize }, UnauthorizedProbe { peer: IpAddr, bytes: usize, reason: String },
KeyCreated { key: String }, KeyCreated { key: String },
Log(String), Log(String),
#[allow(dead_code)] #[allow(dead_code)]
@ -328,10 +328,9 @@ pub async fn run_server(
UiEvent::KeyCreated { key } => { UiEvent::KeyCreated { key } => {
tracing::info!("Access key created: {key}"); tracing::info!("Access key created: {key}");
} }
UiEvent::UnauthorizedProbe { peer, bytes } => { UiEvent::UnauthorizedProbe { peer, bytes, reason } => {
if debug { // Make it a warn so it's always visible outside debug mode!
tracing::debug!("Unauthorized probe from {peer} ({bytes} bytes)"); tracing::warn!("Unauthorized probe from {peer} ({bytes} bytes): {reason}");
}
} }
UiEvent::PeerSeen { .. } => {} UiEvent::PeerSeen { .. } => {}
_ => {} _ => {}
@ -576,8 +575,8 @@ async fn handle_udp_packet(
) -> Result<()> { ) -> Result<()> {
let size = packet.len(); let size = packet.len();
match dispatcher.on_datagram(peer, packet) { match dispatcher.on_datagram(peer, packet) {
Ok(DispatchOutcome::Unauthorized) => { Ok(DispatchOutcome::Unauthorized(reason)) => {
let _ = ui_event_tx.send(UiEvent::UnauthorizedProbe { peer: peer.ip(), bytes: size }); let _ = ui_event_tx.send(UiEvent::UnauthorizedProbe { peer: peer.ip(), bytes: size, reason });
} }
Ok(DispatchOutcome::Accepted { responses, app_payloads, peer_addr }) => { Ok(DispatchOutcome::Accepted { responses, app_payloads, peer_addr }) => {
let peer_ip = peer_addr.ip(); let peer_ip = peer_addr.ip();

View File

@ -12,7 +12,7 @@ pub enum UiEvent {
PeerSeen { peer: IpAddr }, PeerSeen { peer: IpAddr },
Rx { peer: IpAddr, bytes: usize }, Rx { peer: IpAddr, bytes: usize },
Tx { peer: IpAddr, bytes: usize }, Tx { peer: IpAddr, bytes: usize },
UnauthorizedProbe { peer: IpAddr, bytes: usize }, UnauthorizedProbe { peer: IpAddr, bytes: usize, reason: String },
KeyCreated { key: String }, KeyCreated { key: String },
Log(String), Log(String),
KeyCount(usize), KeyCount(usize),