diff --git a/src/proxy/server.rs b/src/proxy/server.rs index 827767d..3dcb3b7 100644 --- a/src/proxy/server.rs +++ b/src/proxy/server.rs @@ -70,6 +70,7 @@ use pingora::proxy::{ProxyHttp, Session}; use pingora::server::configuration; use pingora::services::listening::Service; use pingora::upstreams::peer::{HttpPeer, Peer}; +use scopeguard::defer; use snafu::Snafu; use std::collections::HashMap; use std::sync::atomic::{AtomicI32, AtomicU64, Ordering}; @@ -424,9 +425,12 @@ fn get_digest_detail(digest: &Digest) -> DigestDeailt { impl ProxyHttp for Server { type CTX = State; fn new_ctx(&self) -> Self::CTX { + debug!("new ctx"); State::new() } fn init_downstream_modules(&self, modules: &mut HttpModules) { + debug!("--> init downstream modules"); + defer!(debug!("<-- init downstream modules");); // Add disabled downstream compression module by default modules.add_module(ResponseCompressionBuilder::enable(0)); let Some(value) = &self.modules else { @@ -446,6 +450,9 @@ impl ProxyHttp for Server { where Self::CTX: Send + Sync, { + debug!("--> early request filter"); + defer!(debug!("<-- early request filter");); + if let Some(stream) = session.stream() { ctx.connection_id = stream.id() as usize; } @@ -568,6 +575,8 @@ impl ProxyHttp for Server { where Self::CTX: Send + Sync, { + debug!("--> request filter"); + defer!(debug!("<-- request filter");); if self.admin { self.serve_admin(session, ctx).await?; return Ok(true); @@ -633,6 +642,8 @@ impl ProxyHttp for Server { where Self::CTX: Send + Sync, { + debug!("--> proxy upstream filter"); + defer!(debug!("<-- proxy upstream filter");); if let Some(location) = &ctx.location { let done = location .clone() @@ -650,6 +661,8 @@ impl ProxyHttp for Server { session: &mut Session, ctx: &mut State, ) -> pingora::Result> { + debug!("--> upstream peer"); + defer!(debug!("<-- upstream peer");); let mut location_name = "unknown".to_string(); let peer = if let Some(location) = &ctx.location { location_name.clone_from(&location.name); @@ -697,6 +710,8 @@ impl ProxyHttp for Server { where Self::CTX: Send + Sync, { + debug!("--> connected to upstream"); + defer!(debug!("<-- connected to upstream");); if !reused { if let Some(digest) = digest { let detail = get_digest_detail(digest); @@ -733,6 +748,8 @@ impl ProxyHttp for Server { where Self::CTX: Send + Sync, { + debug!("--> upstream request filter"); + defer!(debug!("<-- upstream request filter");); if let Some(location) = &ctx.location { location.set_append_proxy_headers(session, ctx, upstream_response); } @@ -748,6 +765,8 @@ impl ProxyHttp for Server { where Self::CTX: Send + Sync, { + debug!("--> request body filter"); + defer!(debug!("<-- request body filter");); if let Some(buf) = body { ctx.payload_size += buf.len(); if let Some(location) = &ctx.location { @@ -761,6 +780,8 @@ impl ProxyHttp for Server { session: &Session, ctx: &mut Self::CTX, ) -> pingora::Result { + debug!("--> cache key callback"); + defer!(debug!("<-- cache key callback");); let key = util::get_cache_key( &ctx.cache_prefix.clone().unwrap_or_default(), session.req_header().method.as_ref(), @@ -776,6 +797,8 @@ impl ProxyHttp for Server { resp: &ResponseHeader, ctx: &mut Self::CTX, ) -> pingora::Result { + debug!("--> response cache filter"); + defer!(debug!("<-- response cache filter");); if ctx.check_cache_control && resp.headers.get("Cache-Control").is_none() { @@ -832,6 +855,8 @@ impl ProxyHttp for Server { where Self::CTX: Send + Sync, { + debug!("--> response filter"); + defer!(debug!("<-- response filter");); if session.cache.enabled() { // ignore insert header error let _ = upstream_response.insert_header( @@ -873,6 +898,8 @@ impl ProxyHttp for Server { upstream_response: &mut ResponseHeader, ctx: &mut Self::CTX, ) { + debug!("--> upstream response filter"); + defer!(debug!("<-- upstream response filter");); if ctx.status.is_none() { ctx.status = Some(upstream_response.status); ctx.upstream_response_time = @@ -893,6 +920,8 @@ impl ProxyHttp for Server { end_of_stream: bool, ctx: &mut Self::CTX, ) -> pingora::Result<()> { + debug!("--> upstream response body filter"); + defer!(debug!("<-- upstream response body filter");); if end_of_stream { ctx.upstream_response_time = util::get_latency(&ctx.upstream_response_time); @@ -943,6 +972,8 @@ impl ProxyHttp for Server { where Self::CTX: Send + Sync, { + debug!("--> response body filter"); + defer!(debug!("<-- response body filter");); // set modify response body if let Some(modify) = &ctx.modify_response_body { if let Some(ref mut buf) = ctx.response_body { @@ -978,6 +1009,8 @@ impl ProxyHttp for Server { where Self::CTX: Send + Sync, { + debug!("--> fail to proxy"); + defer!(debug!("<-- fail to proxy");); let server_session = session.as_mut(); let code = match e.etype() { @@ -1058,6 +1091,8 @@ impl ProxyHttp for Server { ) where Self::CTX: Send + Sync, { + debug!("--> logging"); + defer!(debug!("<-- logging");); end_request(); self.processing.fetch_sub(1, Ordering::Relaxed); if let Some(location) = &ctx.location {