fix(rustproxy-http): include request domain in backend proxy error and protocol detection logs
This commit is contained in:
@@ -479,6 +479,7 @@ impl HttpProxyService {
|
||||
}
|
||||
|
||||
let upstream_key = format!("{}:{}", upstream.host, upstream.port);
|
||||
let domain_str = host.as_deref().unwrap_or("-");
|
||||
self.upstream_selector.connection_started(&upstream_key);
|
||||
|
||||
// Check for WebSocket upgrade
|
||||
@@ -622,7 +623,7 @@ impl HttpProxyService {
|
||||
self.metrics.set_backend_protocol(&upstream_key, "h2");
|
||||
let result = self.forward_h2_pooled(
|
||||
sender, parts, body, upstream_headers, &upstream_path,
|
||||
route_match.route, route_id, &ip_str, &pool_key,
|
||||
route_match.route, route_id, &ip_str, &pool_key, domain_str,
|
||||
).await;
|
||||
self.upstream_selector.connection_ended(&upstream_key);
|
||||
return result;
|
||||
@@ -668,6 +669,7 @@ impl HttpProxyService {
|
||||
|
||||
info!(
|
||||
backend = %upstream_key,
|
||||
domain = %domain_str,
|
||||
protocol = if is_h2 { "h2" } else { "h1" },
|
||||
connect_time_ms = %connect_start.elapsed().as_millis(),
|
||||
"Backend protocol detected via ALPN"
|
||||
@@ -684,6 +686,7 @@ impl HttpProxyService {
|
||||
Ok(Err(e)) => {
|
||||
error!(
|
||||
backend = %upstream_key,
|
||||
domain = %domain_str,
|
||||
connect_time_ms = %connect_start.elapsed().as_millis(),
|
||||
error = %e,
|
||||
"Backend TLS connect failed"
|
||||
@@ -695,6 +698,7 @@ impl HttpProxyService {
|
||||
Err(_) => {
|
||||
error!(
|
||||
backend = %upstream_key,
|
||||
domain = %domain_str,
|
||||
connect_time_ms = %connect_start.elapsed().as_millis(),
|
||||
"Backend TLS connect timeout"
|
||||
);
|
||||
@@ -720,6 +724,7 @@ impl HttpProxyService {
|
||||
Ok(Err(e)) => {
|
||||
error!(
|
||||
backend = %upstream_key,
|
||||
domain = %domain_str,
|
||||
connect_time_ms = %connect_start.elapsed().as_millis(),
|
||||
error = %e,
|
||||
"Backend TCP connect failed"
|
||||
@@ -731,6 +736,7 @@ impl HttpProxyService {
|
||||
Err(_) => {
|
||||
error!(
|
||||
backend = %upstream_key,
|
||||
domain = %domain_str,
|
||||
connect_time_ms = %connect_start.elapsed().as_millis(),
|
||||
"Backend TCP connect timeout"
|
||||
);
|
||||
@@ -756,19 +762,19 @@ impl HttpProxyService {
|
||||
self.forward_h2_with_fallback(
|
||||
io, parts, body, upstream_headers, &upstream_path,
|
||||
&upstream, route_match.route, route_id, &ip_str, &final_pool_key,
|
||||
host.clone(),
|
||||
host.clone(), domain_str,
|
||||
).await
|
||||
} else {
|
||||
// Explicit H2 mode: hard-fail on handshake error (preserved behavior)
|
||||
self.forward_h2(
|
||||
io, parts, body, upstream_headers, &upstream_path,
|
||||
&upstream, route_match.route, route_id, &ip_str, &final_pool_key,
|
||||
&upstream, route_match.route, route_id, &ip_str, &final_pool_key, domain_str,
|
||||
).await
|
||||
}
|
||||
} else {
|
||||
self.forward_h1(
|
||||
io, parts, body, upstream_headers, &upstream_path,
|
||||
&upstream, route_match.route, route_id, &ip_str, &final_pool_key,
|
||||
&upstream, route_match.route, route_id, &ip_str, &final_pool_key, domain_str,
|
||||
).await
|
||||
};
|
||||
self.upstream_selector.connection_ended(&upstream_key);
|
||||
@@ -790,6 +796,7 @@ impl HttpProxyService {
|
||||
route_id: Option<&str>,
|
||||
source_ip: &str,
|
||||
pool_key: &crate::connection_pool::PoolKey,
|
||||
domain: &str,
|
||||
) -> Result<Response<BoxBody<Bytes, hyper::Error>>, hyper::Error> {
|
||||
let backend_key = format!("{}:{}", pool_key.host, pool_key.port);
|
||||
|
||||
@@ -798,7 +805,7 @@ impl HttpProxyService {
|
||||
self.metrics.backend_pool_hit(&backend_key);
|
||||
return self.forward_h1_with_sender(
|
||||
pooled_sender, parts, body, upstream_headers, upstream_path,
|
||||
route, route_id, source_ip, pool_key,
|
||||
route, route_id, source_ip, pool_key, domain,
|
||||
).await;
|
||||
}
|
||||
|
||||
@@ -809,7 +816,7 @@ impl HttpProxyService {
|
||||
) = match hyper::client::conn::http1::handshake(io).await {
|
||||
Ok(h) => h,
|
||||
Err(e) => {
|
||||
error!(backend = %backend_key, error = %e, "Backend H1 handshake failed");
|
||||
error!(backend = %backend_key, domain = %domain, error = %e, "Backend H1 handshake failed");
|
||||
self.metrics.backend_handshake_error(&backend_key);
|
||||
return Ok(error_response(StatusCode::BAD_GATEWAY, "Backend handshake failed"));
|
||||
}
|
||||
@@ -821,7 +828,7 @@ impl HttpProxyService {
|
||||
}
|
||||
});
|
||||
|
||||
self.forward_h1_with_sender(sender, parts, body, upstream_headers, upstream_path, route, route_id, source_ip, pool_key).await
|
||||
self.forward_h1_with_sender(sender, parts, body, upstream_headers, upstream_path, route, route_id, source_ip, pool_key, domain).await
|
||||
}
|
||||
|
||||
/// Common H1 forwarding logic used by both fresh and pooled paths.
|
||||
@@ -836,6 +843,7 @@ impl HttpProxyService {
|
||||
route_id: Option<&str>,
|
||||
source_ip: &str,
|
||||
pool_key: &crate::connection_pool::PoolKey,
|
||||
domain: &str,
|
||||
) -> Result<Response<BoxBody<Bytes, hyper::Error>>, hyper::Error> {
|
||||
// Always use HTTP/1.1 for h1 backend connections (h2 incoming requests have version HTTP/2.0)
|
||||
let mut upstream_req = Request::builder()
|
||||
@@ -863,7 +871,7 @@ impl HttpProxyService {
|
||||
Ok(resp) => resp,
|
||||
Err(e) => {
|
||||
let bk = format!("{}:{}", pool_key.host, pool_key.port);
|
||||
error!(backend = %bk, error = %e, "Backend H1 request failed");
|
||||
error!(backend = %bk, domain = %domain, error = %e, "Backend H1 request failed");
|
||||
self.metrics.backend_request_error(&bk);
|
||||
return Ok(error_response(StatusCode::BAD_GATEWAY, "Backend request failed"));
|
||||
}
|
||||
@@ -889,6 +897,7 @@ impl HttpProxyService {
|
||||
route_id: Option<&str>,
|
||||
source_ip: &str,
|
||||
pool_key: &crate::connection_pool::PoolKey,
|
||||
domain: &str,
|
||||
) -> Result<Response<BoxBody<Bytes, hyper::Error>>, hyper::Error> {
|
||||
let backend_key = format!("{}:{}", pool_key.host, pool_key.port);
|
||||
let exec = hyper_util::rt::TokioExecutor::new();
|
||||
@@ -899,7 +908,7 @@ impl HttpProxyService {
|
||||
) = match hyper::client::conn::http2::handshake(exec, io).await {
|
||||
Ok(h) => h,
|
||||
Err(e) => {
|
||||
error!(backend = %backend_key, error = %e, "Backend H2 handshake failed");
|
||||
error!(backend = %backend_key, domain = %domain, error = %e, "Backend H2 handshake failed");
|
||||
self.metrics.backend_handshake_error(&backend_key);
|
||||
return Ok(error_response(StatusCode::BAD_GATEWAY, "Backend H2 handshake failed"));
|
||||
}
|
||||
@@ -914,7 +923,7 @@ impl HttpProxyService {
|
||||
// Register for multiplexed reuse
|
||||
self.connection_pool.register_h2(pool_key.clone(), sender.clone());
|
||||
|
||||
self.forward_h2_with_sender(sender, parts, body, upstream_headers, upstream_path, route, route_id, source_ip, Some(pool_key)).await
|
||||
self.forward_h2_with_sender(sender, parts, body, upstream_headers, upstream_path, route, route_id, source_ip, Some(pool_key), domain).await
|
||||
}
|
||||
|
||||
/// Forward request using an existing (pooled) HTTP/2 sender.
|
||||
@@ -931,6 +940,7 @@ impl HttpProxyService {
|
||||
route_id: Option<&str>,
|
||||
source_ip: &str,
|
||||
pool_key: &crate::connection_pool::PoolKey,
|
||||
domain: &str,
|
||||
) -> Result<Response<BoxBody<Bytes, hyper::Error>>, hyper::Error> {
|
||||
// Save retry state for bodyless requests (cheap: Method is an enum, HeaderMap clones Arc-backed Bytes)
|
||||
let retry_state = if body.is_end_stream() {
|
||||
@@ -941,18 +951,18 @@ impl HttpProxyService {
|
||||
|
||||
let result = self.forward_h2_with_sender(
|
||||
sender, parts, body, upstream_headers, upstream_path,
|
||||
route, route_id, source_ip, Some(pool_key),
|
||||
route, route_id, source_ip, Some(pool_key), domain,
|
||||
).await;
|
||||
|
||||
// If the request failed (502) and we can retry with an empty body, do so
|
||||
let is_502 = matches!(&result, Ok(resp) if resp.status() == StatusCode::BAD_GATEWAY);
|
||||
if is_502 {
|
||||
if let Some((method, headers)) = retry_state {
|
||||
warn!("Stale pooled H2 sender for {}:{}, retrying with fresh connection",
|
||||
pool_key.host, pool_key.port);
|
||||
warn!(backend = %format!("{}:{}", pool_key.host, pool_key.port), domain = %domain,
|
||||
"Stale pooled H2 sender, retrying with fresh connection");
|
||||
return self.retry_h2_with_fresh_connection(
|
||||
method, headers, upstream_path,
|
||||
pool_key, route, route_id, source_ip,
|
||||
pool_key, route, route_id, source_ip, domain,
|
||||
).await;
|
||||
}
|
||||
}
|
||||
@@ -970,6 +980,7 @@ impl HttpProxyService {
|
||||
route: &rustproxy_config::RouteConfig,
|
||||
route_id: Option<&str>,
|
||||
source_ip: &str,
|
||||
domain: &str,
|
||||
) -> Result<Response<BoxBody<Bytes, hyper::Error>>, hyper::Error> {
|
||||
let backend_key = format!("{}:{}", pool_key.host, pool_key.port);
|
||||
|
||||
@@ -982,12 +993,12 @@ impl HttpProxyService {
|
||||
).await {
|
||||
Ok(Ok(tls)) => BackendStream::Tls(tls),
|
||||
Ok(Err(e)) => {
|
||||
error!(backend = %backend_key, error = %e, "H2 retry: TLS connect failed");
|
||||
error!(backend = %backend_key, domain = %domain, error = %e, "H2 retry: TLS connect failed");
|
||||
self.metrics.backend_connect_error(&backend_key);
|
||||
return Ok(error_response(StatusCode::BAD_GATEWAY, "Backend unavailable on H2 retry"));
|
||||
}
|
||||
Err(_) => {
|
||||
error!(backend = %backend_key, "H2 retry: TLS connect timeout");
|
||||
error!(backend = %backend_key, domain = %domain, "H2 retry: TLS connect timeout");
|
||||
self.metrics.backend_connect_error(&backend_key);
|
||||
return Ok(error_response(StatusCode::GATEWAY_TIMEOUT, "Backend timeout on H2 retry"));
|
||||
}
|
||||
@@ -1002,12 +1013,12 @@ impl HttpProxyService {
|
||||
BackendStream::Plain(s)
|
||||
}
|
||||
Ok(Err(e)) => {
|
||||
error!(backend = %backend_key, error = %e, "H2 retry: TCP connect failed");
|
||||
error!(backend = %backend_key, domain = %domain, error = %e, "H2 retry: TCP connect failed");
|
||||
self.metrics.backend_connect_error(&backend_key);
|
||||
return Ok(error_response(StatusCode::BAD_GATEWAY, "Backend unavailable on H2 retry"));
|
||||
}
|
||||
Err(_) => {
|
||||
error!(backend = %backend_key, "H2 retry: TCP connect timeout");
|
||||
error!(backend = %backend_key, domain = %domain, "H2 retry: TCP connect timeout");
|
||||
self.metrics.backend_connect_error(&backend_key);
|
||||
return Ok(error_response(StatusCode::GATEWAY_TIMEOUT, "Backend timeout on H2 retry"));
|
||||
}
|
||||
@@ -1023,7 +1034,7 @@ impl HttpProxyService {
|
||||
) = match hyper::client::conn::http2::handshake(exec, io).await {
|
||||
Ok(h) => h,
|
||||
Err(e) => {
|
||||
error!(backend = %backend_key, error = %e, "H2 retry: handshake failed");
|
||||
error!(backend = %backend_key, domain = %domain, error = %e, "H2 retry: handshake failed");
|
||||
self.metrics.backend_handshake_error(&backend_key);
|
||||
return Ok(error_response(StatusCode::BAD_GATEWAY, "Backend H2 retry handshake failed"));
|
||||
}
|
||||
@@ -1055,15 +1066,15 @@ impl HttpProxyService {
|
||||
match sender.send_request(upstream_req).await {
|
||||
Ok(resp) => {
|
||||
let result = self.build_streaming_response(resp, route, route_id, source_ip).await;
|
||||
// Close the fresh backend connection (opened at line 1016 above)
|
||||
// Close the fresh backend connection (opened above)
|
||||
self.metrics.backend_connection_closed(&backend_key);
|
||||
result
|
||||
}
|
||||
Err(e) => {
|
||||
error!(backend = %backend_key, error = %e, "H2 retry: request failed");
|
||||
error!(backend = %backend_key, domain = %domain, error = %e, "H2 retry: request failed");
|
||||
self.metrics.backend_request_error(&backend_key);
|
||||
self.connection_pool.remove_h2(pool_key);
|
||||
// Close the fresh backend connection (opened at line 1016 above)
|
||||
// Close the fresh backend connection (opened above)
|
||||
self.metrics.backend_connection_closed(&backend_key);
|
||||
Ok(error_response(StatusCode::BAD_GATEWAY, "Backend H2 request failed on retry"))
|
||||
}
|
||||
@@ -1090,6 +1101,7 @@ impl HttpProxyService {
|
||||
source_ip: &str,
|
||||
pool_key: &crate::connection_pool::PoolKey,
|
||||
requested_host: Option<String>,
|
||||
domain: &str,
|
||||
) -> Result<Response<BoxBody<Bytes, hyper::Error>>, hyper::Error> {
|
||||
let exec = hyper_util::rt::TokioExecutor::new();
|
||||
let handshake_result: Result<(
|
||||
@@ -1145,6 +1157,7 @@ impl HttpProxyService {
|
||||
let bk = format!("{}:{}", upstream.host, upstream.port);
|
||||
warn!(
|
||||
backend = %bk,
|
||||
domain = %domain,
|
||||
error = %e,
|
||||
"Auto-detect: H2 request failed, falling back to H1"
|
||||
);
|
||||
@@ -1158,7 +1171,7 @@ impl HttpProxyService {
|
||||
|
||||
// Retry as H1 for bodyless requests; return 502 for requests with bodies
|
||||
if let Some((method, headers)) = retry_state {
|
||||
match self.reconnect_backend(upstream).await {
|
||||
match self.reconnect_backend(upstream, domain).await {
|
||||
Some(fallback_backend) => {
|
||||
let h1_pool_key = crate::connection_pool::PoolKey {
|
||||
host: upstream.host.clone(),
|
||||
@@ -1169,7 +1182,7 @@ impl HttpProxyService {
|
||||
let fallback_io = TokioIo::new(fallback_backend);
|
||||
let result = self.forward_h1_empty_body(
|
||||
fallback_io, method, headers, upstream_path,
|
||||
route, route_id, source_ip, &h1_pool_key,
|
||||
route, route_id, source_ip, &h1_pool_key, domain,
|
||||
).await;
|
||||
// Close the reconnected backend connection (opened in reconnect_backend)
|
||||
self.metrics.backend_connection_closed(&bk);
|
||||
@@ -1191,6 +1204,7 @@ impl HttpProxyService {
|
||||
let bk = format!("{}:{}", upstream.host, upstream.port);
|
||||
warn!(
|
||||
backend = %bk,
|
||||
domain = %domain,
|
||||
error = %e,
|
||||
"H2 handshake failed, falling back to H1"
|
||||
);
|
||||
@@ -1206,7 +1220,7 @@ impl HttpProxyService {
|
||||
self.protocol_cache.insert(cache_key, crate::protocol_cache::DetectedProtocol::H1);
|
||||
|
||||
// Reconnect for H1 (the original io was consumed by the failed h2 handshake)
|
||||
match self.reconnect_backend(upstream).await {
|
||||
match self.reconnect_backend(upstream, domain).await {
|
||||
Some(fallback_backend) => {
|
||||
let h1_pool_key = crate::connection_pool::PoolKey {
|
||||
host: upstream.host.clone(),
|
||||
@@ -1217,7 +1231,7 @@ impl HttpProxyService {
|
||||
let fallback_io = TokioIo::new(fallback_backend);
|
||||
let result = self.forward_h1(
|
||||
fallback_io, parts, body, upstream_headers, upstream_path,
|
||||
upstream, route, route_id, source_ip, &h1_pool_key,
|
||||
upstream, route, route_id, source_ip, &h1_pool_key, domain,
|
||||
).await;
|
||||
// Close the reconnected backend connection (opened in reconnect_backend)
|
||||
self.metrics.backend_connection_closed(&bk);
|
||||
@@ -1243,6 +1257,7 @@ impl HttpProxyService {
|
||||
route_id: Option<&str>,
|
||||
source_ip: &str,
|
||||
pool_key: &crate::connection_pool::PoolKey,
|
||||
domain: &str,
|
||||
) -> Result<Response<BoxBody<Bytes, hyper::Error>>, hyper::Error> {
|
||||
let backend_key = format!("{}:{}", pool_key.host, pool_key.port);
|
||||
let (mut sender, conn): (
|
||||
@@ -1251,7 +1266,7 @@ impl HttpProxyService {
|
||||
) = match hyper::client::conn::http1::handshake(io).await {
|
||||
Ok(h) => h,
|
||||
Err(e) => {
|
||||
error!(backend = %backend_key, error = %e, "H1 fallback: handshake failed");
|
||||
error!(backend = %backend_key, domain = %domain, error = %e, "H1 fallback: handshake failed");
|
||||
self.metrics.backend_handshake_error(&backend_key);
|
||||
return Ok(error_response(StatusCode::BAD_GATEWAY, "Backend H1 fallback handshake failed"));
|
||||
}
|
||||
@@ -1280,7 +1295,7 @@ impl HttpProxyService {
|
||||
let upstream_response = match sender.send_request(upstream_req).await {
|
||||
Ok(resp) => resp,
|
||||
Err(e) => {
|
||||
error!(backend = %backend_key, error = %e, "H1 fallback: request failed");
|
||||
error!(backend = %backend_key, domain = %domain, error = %e, "H1 fallback: request failed");
|
||||
self.metrics.backend_request_error(&backend_key);
|
||||
return Ok(error_response(StatusCode::BAD_GATEWAY, "Backend H1 fallback request failed"));
|
||||
}
|
||||
@@ -1296,6 +1311,7 @@ impl HttpProxyService {
|
||||
async fn reconnect_backend(
|
||||
&self,
|
||||
upstream: &crate::upstream_selector::UpstreamSelection,
|
||||
domain: &str,
|
||||
) -> Option<BackendStream> {
|
||||
let backend_key = format!("{}:{}", upstream.host, upstream.port);
|
||||
let reconnect_start = std::time::Instant::now();
|
||||
@@ -1309,12 +1325,12 @@ impl HttpProxyService {
|
||||
Some(BackendStream::Tls(tls))
|
||||
}
|
||||
Ok(Err(e)) => {
|
||||
error!(backend = %backend_key, error = %e, "H1 fallback: TLS reconnect failed");
|
||||
error!(backend = %backend_key, domain = %domain, error = %e, "H1 fallback: TLS reconnect failed");
|
||||
self.metrics.backend_connect_error(&backend_key);
|
||||
None
|
||||
}
|
||||
Err(_) => {
|
||||
error!(backend = %backend_key, "H1 fallback: TLS reconnect timeout");
|
||||
error!(backend = %backend_key, domain = %domain, "H1 fallback: TLS reconnect timeout");
|
||||
self.metrics.backend_connect_error(&backend_key);
|
||||
None
|
||||
}
|
||||
@@ -1333,12 +1349,12 @@ impl HttpProxyService {
|
||||
Some(BackendStream::Plain(s))
|
||||
}
|
||||
Ok(Err(e)) => {
|
||||
error!(backend = %backend_key, error = %e, "H1 fallback: TCP reconnect failed");
|
||||
error!(backend = %backend_key, domain = %domain, error = %e, "H1 fallback: TCP reconnect failed");
|
||||
self.metrics.backend_connect_error(&backend_key);
|
||||
None
|
||||
}
|
||||
Err(_) => {
|
||||
error!(backend = %backend_key, "H1 fallback: TCP reconnect timeout");
|
||||
error!(backend = %backend_key, domain = %domain, "H1 fallback: TCP reconnect timeout");
|
||||
self.metrics.backend_connect_error(&backend_key);
|
||||
None
|
||||
}
|
||||
@@ -1358,6 +1374,7 @@ impl HttpProxyService {
|
||||
route_id: Option<&str>,
|
||||
source_ip: &str,
|
||||
pool_key: Option<&crate::connection_pool::PoolKey>,
|
||||
domain: &str,
|
||||
) -> Result<Response<BoxBody<Bytes, hyper::Error>>, hyper::Error> {
|
||||
let mut upstream_req = Request::builder()
|
||||
.method(parts.method)
|
||||
@@ -1385,11 +1402,11 @@ impl HttpProxyService {
|
||||
// Evict the dead sender so subsequent requests get fresh connections
|
||||
if let Some(key) = pool_key {
|
||||
let bk = format!("{}:{}", key.host, key.port);
|
||||
error!(backend = %bk, error = %e, "Backend H2 request failed");
|
||||
error!(backend = %bk, domain = %domain, error = %e, "Backend H2 request failed");
|
||||
self.metrics.backend_request_error(&bk);
|
||||
self.connection_pool.remove_h2(key);
|
||||
} else {
|
||||
error!(error = %e, "Backend H2 request failed");
|
||||
error!(domain = %domain, error = %e, "Backend H2 request failed");
|
||||
}
|
||||
return Ok(error_response(StatusCode::BAD_GATEWAY, "Backend H2 request failed"));
|
||||
}
|
||||
|
||||
Reference in New Issue
Block a user