diff --git a/node/src/proxy_server/client_request_payload_factory.rs b/node/src/proxy_server/client_request_payload_factory.rs index 3bebeb7ea..4f9e5df60 100644 --- a/node/src/proxy_server/client_request_payload_factory.rs +++ b/node/src/proxy_server/client_request_payload_factory.rs @@ -40,8 +40,10 @@ impl ClientRequestPayloadFactory for ClientRequestPayloadFactoryReal { // So far we've only looked in the client packet; but this message will evaporate // unless there's no host information in host_opt (from ProxyServer's StreamInfo) either. None => Err(format!( - "No hostname information found in either client packet or ProxyServer for protocol {:?}", - protocol_pack.proxy_protocol() + "No hostname information found in either client packet ({}) or ProxyServer for protocol {:?}, with StreamKey {}", + protocol_pack.describe_packet(&data), + protocol_pack.proxy_protocol(), + stream_key )), } }); @@ -49,6 +51,16 @@ impl ClientRequestPayloadFactory for ClientRequestPayloadFactoryReal { (Ok(host), _) => host, (Err(_), Some(host)) => host, (Err(e), None) => { + if ibcd.last_data && ibcd.data.is_empty() { + warning!( + logger, + "Client opened {:?} connection and immediately closed it without sending any data, with StreamKey {}", + protocol_pack.proxy_protocol(), + stream_key + ); + } else { + error!(logger, "{}", e); + } error!(logger, "{}", e); return None; } @@ -187,7 +199,32 @@ mod tests { let result = subject.make(&ibcd, stream_key, None, cryptde.as_ref(), &logger); assert_eq!(result, None); - TestLogHandler::new().exists_log_containing(&format!("ERROR: {test_name}: No hostname information found in either client packet or ProxyServer for protocol HTTP")); + TestLogHandler::new().exists_log_containing(&format!("ERROR: {test_name}: No hostname information found in either client packet (Malformed HTTP request: '') or ProxyServer for protocol HTTP")); + } + + #[test] + fn logs_different_error_and_returns_none_if_connection_is_opened_and_immediately_closed() { + init_test_logging(); + let test_name = + "logs_different_error_and_returns_none_if_connection_is_opened_and_immediately_closed"; + let ibcd = InboundClientData { + timestamp: SystemTime::now(), + client_addr: SocketAddr::from_str("1.2.3.4:5678").unwrap(), + reception_port_opt: Some(HTTP_PORT), + sequence_number_opt: Some(1), + last_data: true, + is_clandestine: false, + data: vec![], + }; + let cryptde = CRYPTDE_PAIR.main.dup(); + let stream_key = StreamKey::make_meaningful_stream_key(test_name); + let logger = Logger::new(test_name); + let subject = Box::new(ClientRequestPayloadFactoryReal::new()); + + let result = subject.make(&ibcd, stream_key, None, cryptde.as_ref(), &logger); + + assert_eq!(result, None); + TestLogHandler::new().exists_log_containing(&format!("WARN: {test_name}: Client opened HTTP connection and immediately closed it without sending any data")); } #[test] @@ -353,7 +390,7 @@ mod tests { let result = subject.make(&ibcd, stream_key, None, cryptde, &logger); assert_eq!(result, None); - TestLogHandler::new().exists_log_containing(&format!("ERROR: {test_name}: No hostname information found in either client packet or ProxyServer for protocol TLS")); + TestLogHandler::new().exists_log_containing(&format!("ERROR: {test_name}: No hostname information found in either client packet (ClientHello with no SNI extension) or ProxyServer for protocol TLS")); } #[test] diff --git a/node/src/proxy_server/http_protocol_pack.rs b/node/src/proxy_server/http_protocol_pack.rs index 523e34e3b..ef8940c6d 100644 --- a/node/src/proxy_server/http_protocol_pack.rs +++ b/node/src/proxy_server/http_protocol_pack.rs @@ -35,6 +35,14 @@ impl ProtocolPack for HttpProtocolPack { fn server_impersonator(&self) -> Box { Box::new(ServerImpersonatorHttp {}) } + + fn describe_packet(&self, data: &PlainData) -> String { + if data.as_slice().starts_with(b"HTTP/") { + self.describe_response(data) + } else { + self.describe_request(data) + } + } } impl HttpProtocolPack { @@ -102,6 +110,82 @@ impl HttpProtocolPack { Ok(port) => Ok(port), } } + + fn describe_request(&self, data: &PlainData) -> String { + let first_line_end = data + .as_slice() + .iter() + .position(|&b| b == b'\r') + .unwrap_or(data.len()); + let first_line = &data.as_slice()[0..first_line_end]; + let mut parts = first_line.split(|&b| b == b' '); + if let (Some(method_bytes), Some(path_bytes), Some(http_version_bytes)) = + (parts.next(), parts.next(), parts.next()) + { + let method = Self::from_utf8(method_bytes); + let path = Self::from_utf8(path_bytes); + let http_version = Self::from_utf8(http_version_bytes); + if let Some(host) = self.find_host(data) { + return if path.starts_with('/') { + format!( + "{} {} request to {}{}", + http_version, method, host.name, path + ) + } else { + format!("{} {} request to {}", http_version, method, path) + }; + } else { + return format!( + "{} {} request to unknown host: {}", + http_version, method, path + ); + } + } + format!( + "Malformed HTTP request: {}", + Self::truncate_data_as_string(data, 50) + ) + } + + fn describe_response(&self, data: &PlainData) -> String { + let first_line_end = data + .as_slice() + .iter() + .position(|&b| b == b'\r') + .unwrap_or(data.as_slice().len()); + let first_line = &data.as_slice()[0..first_line_end]; + let mut parts = first_line.split(|&b| b == b' '); + if let (Some(http_version_bytes), Some(status_code_bytes), Some(status_text_bytes)) = + (parts.next(), parts.next(), parts.next()) + { + let http_with_version = Self::from_utf8(http_version_bytes); + let status_code = Self::from_utf8(status_code_bytes); + let status_text = Self::from_utf8(status_text_bytes); + return format!( + "{} response with status {} {}", + http_with_version, status_code, status_text + ); + } + format!( + "Malformed HTTP response: {}", + Self::truncate_data_as_string(data, 50) + ) + } + + fn truncate_data_as_string(data: &PlainData, truncate_at: usize) -> String { + if data.as_slice().len() > truncate_at { + format!( + "'{}'...", + String::from_utf8_lossy(&data.as_slice()[0..truncate_at]) + ) + } else { + format!("'{}'", String::from_utf8_lossy(data.as_slice())) + } + } + + fn from_utf8(bytes: &[u8]) -> String { + String::from_utf8_lossy(bytes).to_string() + } } #[cfg(test)] @@ -338,4 +422,83 @@ mod tests { let data = b"CONNECTX"; assert!(!HttpProtocolPack::is_connect(data)); } + + #[test] + fn describe_packet_works_on_get_request_with_header_host() { + let data = + PlainData::new(b"GET /index.html?item=booga HTTP/1.1\r\nHost: www.example.com\r\n\r\n"); + let subject = HttpProtocolPack {}; + + let result = subject.describe_packet(&data); + + assert_eq!( + result, + "HTTP/1.1 GET request to www.example.com/index.html?item=booga" + ); + } + + #[test] + fn describe_packet_works_on_post_request_with_url_host() { + let data = PlainData::new( + b"POST www.example.com/person/1234 HTTP/1.1\r\nContent-Length: 2\r\n\r\n{}", + ); + let subject = HttpProtocolPack {}; + + let result = subject.describe_packet(&data); + + assert_eq!( + result, + "HTTP/1.1 POST request to www.example.com/person/1234" + ); + } + + #[test] + fn describe_packet_works_on_unexpected_request_with_unspecified_host() { + let data = PlainData::new(b"BOOGA /person/1234 HTTP/1.1\r\nContent-Length: 2\r\n\r\n{}"); + let subject = HttpProtocolPack {}; + + let result = subject.describe_packet(&data); + + assert_eq!( + result, + "HTTP/1.1 BOOGA request to unknown host: /person/1234" + ); + } + + #[test] + fn describe_packet_works_on_malformed_request() { + let data = PlainData::new(b"Fourscore_and_seven_years_ago_our_fathers_brought_forth_on_this_continent_a_new_nation,_conceived_in_liberty_and_dedicated_to_the_proposition_that_all_men_are_created_equal."); + let subject = HttpProtocolPack {}; + + let result = subject.describe_packet(&data); + + assert_eq!( + result, + "Malformed HTTP request: 'Fourscore_and_seven_years_ago_our_fathers_brought_'..." + ); + } + + #[test] + fn describe_packet_works_on_200_response() { + let data = + PlainData::new(b"HTTP/1.1 200 OK\r\nContent-Type: text/html\r\n\r\n"); + let subject = HttpProtocolPack {}; + + let result = subject.describe_packet(&data); + + assert_eq!(result, "HTTP/1.1 response with status 200 OK"); + } + + #[test] + fn describe_packet_works_on_malformed_response() { + let data = PlainData::new(b"HTTP/Fourscore_and_seven_years_ago_our_fathers_brought_forth_on_this_continent_a_new_nation,_conceived_in_liberty_and_dedicated_to_the_proposition_that_all_men_are_created_equal."); + let subject = HttpProtocolPack {}; + + let result = subject.describe_packet(&data); + + assert_eq!( + result, + "Malformed HTTP response: 'HTTP/Fourscore_and_seven_years_ago_our_fathers_bro'..." + ); + } } diff --git a/node/src/proxy_server/protocol_pack.rs b/node/src/proxy_server/protocol_pack.rs index 080a9050e..e5607bb08 100644 --- a/node/src/proxy_server/protocol_pack.rs +++ b/node/src/proxy_server/protocol_pack.rs @@ -12,6 +12,7 @@ pub trait ProtocolPack: Send + Sync { fn standard_port(&self) -> u16; fn find_host(&self, data: &PlainData) -> Option; fn server_impersonator(&self) -> Box; + fn describe_packet(&self, data: &PlainData) -> String; } pub fn from_protocol(protocol: ProxyProtocol) -> Box { diff --git a/node/src/proxy_server/tls_protocol_pack.rs b/node/src/proxy_server/tls_protocol_pack.rs index 1ede34301..bb81f8543 100644 --- a/node/src/proxy_server/tls_protocol_pack.rs +++ b/node/src/proxy_server/tls_protocol_pack.rs @@ -39,6 +39,21 @@ impl ProtocolPack for TlsProtocolPack { fn server_impersonator(&self) -> Box { Box::new(ServerImpersonatorTls {}) } + + fn describe_packet(&self, data: &PlainData) -> String { + match data.get_u8(0) { + Some(0x16u8) => self.describe_handshake(data), + Some(0x14u8) => self.describe_cipher_spec(data), + Some(0x15u8) => self.describe_alert(data), + Some(0x17u8) => self.describe_application_data(data), + Some(opcode) => format!( + "{}-byte packet of unrecognized type 0x{:02X}", + data.len(), + opcode + ), + None => format!("Incomplete {}-byte TLS packet", data.len()), + } + } } impl TlsProtocolPack { @@ -101,6 +116,89 @@ impl TlsProtocolPack { Err(_) => Err(()), } } + + fn describe_handshake(&self, data: &PlainData) -> String { + match data.get_u8(5) { + Some(0x00u8) => "HelloRequest".to_string(), + Some(0x01u8) => self.describe_client_hello(data), + Some(0x02u8) => "ServerHello".to_string(), + Some(0x03u8) => "HelloVerifyRequest".to_string(), + Some(0x04u8) => "NewSessionTicket".to_string(), + Some(0x05u8) => "EndOfEarlyData".to_string(), + Some(0x06u8) => "HelloRetryRequest".to_string(), + Some(0x0Bu8) => "Certificate".to_string(), + Some(0x0Cu8) => "ServerKeyExchange".to_string(), + Some(0x0Du8) => "CertificateRequest".to_string(), + Some(0x0Eu8) => "ServerHelloDone".to_string(), + Some(0x0Fu8) => "CertificateVerify".to_string(), + Some(0x10u8) => "ClientKeyExchange".to_string(), + Some(0x14u8) => "Finished".to_string(), + Some(opcode) => format!("Unrecognized Handshake 0x{:02X}", opcode), + None => format!("Incomplete {}-byte Handshake packet", data.len()), + } + } + + fn describe_client_hello(&self, data: &PlainData) -> String { + match self.find_host(data) { + Some(host) => format!("ClientHello with SNI '{}'", host.name), + None => "ClientHello with no SNI extension".to_string(), + } + } + + fn describe_cipher_spec(&self, data: &PlainData) -> String { + match data.get_u8(5) { + Some(0x01u8) => "ChangeCipherSpec".to_string(), + Some(opcode) => format!("Unrecognized ChangeCipherSpec 0x{:02X}", opcode), + None => format!("Incomplete {}-byte ChangeCipherSpec packet", data.len()), + } + } + + fn describe_alert(&self, data: &PlainData) -> String { + let level = match data.get_u8(5) { + Some(0x01u8) => "Warning".to_string(), + Some(0x02u8) => "Fatal".to_string(), + Some(opcode) => format!("Unrecognized Alert Level 0x{:02X}", opcode), + None => return format!("Incomplete {}-byte Alert packet", data.len()), + }; + let description = match data.get_u8(6) { + Some(0x00) => "CloseNotify".to_string(), + Some(0x01) => "Unrecognized Alert Description 0x01".to_string(), + Some(0x0A) => "UnexpectedMessage".to_string(), + Some(0x14) => "BadRecordMAC".to_string(), + Some(0x15) => "DecryptionFailed".to_string(), + Some(0x16) => "RecordOverflow".to_string(), + Some(0x1E) => "DecompressionFailure".to_string(), + Some(0x28) => "HandshakeFailure".to_string(), + Some(0x29) => "NoCertificate".to_string(), + Some(0x2A) => "BadCertificate".to_string(), + Some(0x2B) => "UnsupportedCertificate".to_string(), + Some(0x2C) => "CertificateRevoked".to_string(), + Some(0x2D) => "CertificateExpired".to_string(), + Some(0x2E) => "CertificateUnknown".to_string(), + Some(0x2F) => "IllegalParameter".to_string(), + Some(0x30) => "UnknownCA".to_string(), + Some(0x31) => "AccessDenied".to_string(), + Some(0x32) => "DecodeError".to_string(), + Some(0x33) => "DecryptError".to_string(), + Some(0x3C) => "ExportRestriction".to_string(), + Some(0x46) => "ProtocolVersion".to_string(), + Some(0x47) => "InsufficientSecurity".to_string(), + Some(0x50) => "InternalError".to_string(), + Some(0x5A) => "UserCanceled".to_string(), + Some(0x64) => "NoRenegotiation".to_string(), + Some(0x72) => "UnsupportedExtension".to_string(), + Some(opcode) => format!("Unrecognized Alert Description 0x{:02X}", opcode), + None => return format!("Incomplete {}-byte Alert packet", data.len()), + }; + format!("{} {}", level, description) + } + + fn describe_application_data(&self, data: &PlainData) -> String { + if data.len() < 5 { + return "Incomplete ApplicationData".to_string(); + } + format!("{}-byte ApplicationData", data.len() - 5) + } } #[cfg(test)] @@ -798,4 +896,256 @@ mod tests { assert_eq!(None, result); } + + #[test] + fn describe_packet_handles_empty_packet() { + let data = PlainData::new(&[]); + + let result = TlsProtocolPack {}.describe_packet(&data); + + assert_eq!("Incomplete 0-byte TLS packet", result); + } + + #[test] + fn describe_packet_handles_unrecognized_packet_type() { + let data = PlainData::new(&[0xFFu8]); + + let result = TlsProtocolPack {}.describe_packet(&data); + + assert_eq!("1-byte packet of unrecognized type 0xFF", result); + } + + #[test] + fn describe_packet_handles_short_handshake_packet() { + let data = PlainData::new(&[0x16u8]); + + let result = TlsProtocolPack {}.describe_packet(&data); + + assert_eq!("Incomplete 1-byte Handshake packet", result); + } + + #[test] + fn identifies_client_hello_with_sni() { + #[rustfmt::skip] + let data = PlainData::new(&[ + 0x16, // content_type: Handshake + 0x00, 0x00, 0x00, 0x00, // version, length: don't care + 0x01, // handshake_type: ClientHello + 0x00, 0x00, 0x00, 0x00, 0x00, // length, version: don't care + 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, + 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, + 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, + 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, // random: don't care + 0x01, // session_id_length + 0x00, // session_id: don't care + 0x00, 0x01, // cipher_suites_length + 0x00, // cipher_suite: don't care + 0x01, // compression_methods_length + 0x00, // compression_method: don't care + 0x00, 0x13, // extensions_length + 0x00, 0x00, // extension_type: server_name + 0x00, 0x0F, // extension_length + 0x00, 0x0D, // server_name_list_length + 0x00, // server_name_type + 0x00, 0x0A, // server_name_length + b's', b'e', b'r', b'v', b'e', b'r', b'.', b'c', + b'o', b'm', // server_name + ]); + + let result = TlsProtocolPack {}.describe_packet(&data); + + assert_eq!("ClientHello with SNI 'server.com'", result); + } + + #[test] + fn identifies_client_hello_without_sni() { + #[rustfmt::skip] + let data = PlainData::new(&[ + 0x16, // content_type: Handshake + 0x00, 0x00, 0x00, 0x00, // version, length: don't care + 0x01, // handshake_type: ClientHello + 0x00, 0x00, 0x00, 0x00, 0x00, // length, version: don't care + 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, + 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, + 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, + 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, // random: don't care + 0x00, // session_id_length + 0x00, 0x00, // cipher_suites_length + 0x00, // compression_methods_length + 0x00, 0x00, // extensions_length + ]); + + let result = TlsProtocolPack {}.describe_packet(&data); + + assert_eq!("ClientHello with no SNI extension", result); + } + + #[test] + fn identifies_other_handshakes() { + #[rustfmt::skip] + let mut bytes: Vec = vec![ + 0x16, // content_type: Handshake + 0x00, 0x00, 0x00, 0x00, // version, length: don't care + 0x00, // handshake_type: replace me + ]; + let handshake_types = vec![ + (0x00, "HelloRequest"), + (0x02, "ServerHello"), + (0x03, "HelloVerifyRequest"), + (0x04, "NewSessionTicket"), + (0x05, "EndOfEarlyData"), + (0x06, "HelloRetryRequest"), + (0x07, "Unrecognized Handshake 0x07"), + (0x08, "Unrecognized Handshake 0x08"), + (0x0B, "Certificate"), + (0x0C, "ServerKeyExchange"), + (0x0D, "CertificateRequest"), + (0x0E, "ServerHelloDone"), + (0x0F, "CertificateVerify"), + (0x10, "ClientKeyExchange"), + (0x14, "Finished"), + ]; + handshake_types.iter().for_each(|(opcode, name)| { + bytes[5] = *opcode; + let data = PlainData::new(&bytes); + + let result = TlsProtocolPack {}.describe_packet(&data); + + assert_eq!(*name, result); + }); + } + + #[test] + fn identifies_cipher_spec_packets() { + #[rustfmt::skip] + let mut bytes: Vec = vec![ + 0x14, // content_type: ChangeCipherSpec + 0x00, 0x00, 0x00, 0x00, // version, length: don't care + 0x00, // change_cipher_spec: replace me + ]; + let change_cipher_specs = vec![ + (0x00, "Unrecognized ChangeCipherSpec 0x00"), + (0x01, "ChangeCipherSpec"), + (0x02, "Unrecognized ChangeCipherSpec 0x02"), + ]; + change_cipher_specs.iter().for_each(|(opcode, name)| { + bytes[5] = *opcode; + let data = PlainData::new(&bytes); + + let result = TlsProtocolPack {}.describe_packet(&data); + + assert_eq!(*name, result); + }); + } + + #[test] + fn handles_incomplete_cipher_spec_packet() { + #[rustfmt::skip] + let data = PlainData::new(&[ + 0x14, // content_type: ChangeCipherSpec + ]); + + let result = TlsProtocolPack {}.describe_packet(&data); + + assert_eq!("Incomplete 1-byte ChangeCipherSpec packet", result); + } + + #[test] + fn identifies_alert_packets() { + #[rustfmt::skip] + let mut bytes: Vec = vec![ + 0x15, // content_type: Alert + 0x00, 0x00, 0x00, 0x00, // version, length: don't care + 0x00, // alert_level: replace me + 0x00, // alert_description: replace me + ]; + let alert_levels = vec![ + (0x01, "Warning"), + (0x02, "Fatal"), + (0x03, "Unrecognized Alert Level 0x03"), + (0x04, "Unrecognized Alert Level 0x04"), + ]; + let alert_descriptions = vec![ + (0x00, "CloseNotify"), + (0x01, "Unrecognized Alert Description 0x01"), + (0x0A, "UnexpectedMessage"), + (0x14, "BadRecordMAC"), + (0x15, "DecryptionFailed"), + (0x16, "RecordOverflow"), + (0x1E, "DecompressionFailure"), + (0x28, "HandshakeFailure"), + (0x29, "NoCertificate"), + (0x2A, "BadCertificate"), + (0x2B, "UnsupportedCertificate"), + (0x2C, "CertificateRevoked"), + (0x2D, "CertificateExpired"), + (0x2E, "CertificateUnknown"), + (0x2F, "IllegalParameter"), + (0x30, "UnknownCA"), + (0x31, "AccessDenied"), + (0x32, "DecodeError"), + (0x33, "DecryptError"), + (0x3C, "ExportRestriction"), + (0x46, "ProtocolVersion"), + (0x47, "InsufficientSecurity"), + (0x50, "InternalError"), + (0x5A, "UserCanceled"), + (0x64, "NoRenegotiation"), + (0x72, "UnsupportedExtension"), + (0xFF, "Unrecognized Alert Description 0xFF"), + ]; + alert_descriptions + .iter() + .for_each(|(description, description_name)| { + bytes[6] = *description; + alert_levels.iter().for_each(|(level, level_name)| { + bytes[5] = *level; + let data = PlainData::new(&bytes); + + let result = TlsProtocolPack {}.describe_packet(&data); + + let expected = format!("{} {}", level_name, description_name); + assert_eq!(expected, result); + }); + }); + } + + #[test] + fn handles_incomplete_alert_packet() { + #[rustfmt::skip] + let data = PlainData::new(&[ + 0x15, // content_type: Alert + ]); + + let result = TlsProtocolPack {}.describe_packet(&data); + + assert_eq!("Incomplete 1-byte Alert packet", result); + } + + #[test] + fn identifies_application_data_packets() { + #[rustfmt::skip] + let data = PlainData::new(&[ + 0x17, // content_type: ApplicationData + 0x00, 0x00, 0x00, 0x00, // version, length: don't care + 0x01, 0x02, 0x03, 0x04, 0x05, // data + ]); + + let result = TlsProtocolPack {}.describe_packet(&data); + + assert_eq!("5-byte ApplicationData", result); + } + + #[test] + fn handles_short_application_data_packets() { + #[rustfmt::skip] + let data = PlainData::new(&[ + 0x17, // content_type: ApplicationData + 0x00, 0x00, 0x00, // Too short by one byte + ]); + + let result = TlsProtocolPack {}.describe_packet(&data); + + assert_eq!("Incomplete ApplicationData", result); + } }