upstream_request_filter not working

[neodes-h]

upstream_request_filter not working

When I was trying to run the load-balancing example code in quickguide, it seems like the function upstream_request_filter is never executed.

My code is:

use std::sync::Arc;

use async_trait::async_trait;
use pingora::prelude::*;
fn main() {
    let mut server = Server::new(None).unwrap();
    server.bootstrap();

    let upstream = LoadBalancer::try_from_iter(&["1.1.1.1:443", "1.0.0.1:443"]).unwrap();

    let mut lb = http_proxy_service(&server.configuration, LB(Arc::new(upstream)));
    lb.add_tcp("0.0.0.0:8080");
    server.add_service(lb);

    server.run_forever();
}

pub struct LB(Arc<LoadBalancer<RoundRobin>>);

#[async_trait]
impl ProxyHttp for LB {
    type CTX = ();

    fn new_ctx(&self) -> Self::CTX {
        ()
    }

    async fn upstream_peer(&self, _session: &mut Session, _ctx: &mut ()) -> Result<Box<HttpPeer>> {
        let upstream = self.0.select(b"", 256).unwrap();
        println!("upstream is {:?}", upstream);
        let peer = Box::new(HttpPeer::new(upstream, true, "one.one.one.one".to_string()));
        Ok(peer)
    }

    async fn upstream_request_filter(
        &self,
        _session: &mut Session,
        upstream_request: &mut RequestHeader,
        _ctx: &mut Self::CTX,
    ) -> Result<()> {
        println!("Entered upstream_request_filter");
        upstream_request
            .insert_header("Host", "one.one.one.one")
            .unwrap();
        Ok(())
    }
}

When I run the code above in terminal 1 and send request using curl curl -v 127.0.0.1:8080 in terminal 2, there is only one output for each request

upstream is Backend { addr: Inet(1.0.0.1:443), weight: 1 }

The curl output is

*   Trying 127.0.0.1:8080...
* Connected to 127.0.0.1 (127.0.0.1) port 8080 (#0)
> GET / HTTP/1.1
> Host: 127.0.0.1:8080
> User-Agent: curl/7.81.0
> Accept: */*
> 
* Mark bundle as not supporting multiuse
< HTTP/1.1 502 Bad Gateway
< Server: Pingora
< Date: Fri, 01 Mar 2024 06:47:46 GMT
< Content-Length: 0
< Cache-Control: private, no-store
< Connection: close
< 
* Closing connection 0
*

If I understand correctly, the expected behaviors should be:

1. "Entered upstream_request_filter" should be outputed in terminal 1.
2. The request header in curl detail shoule be "Host: one.one.one.one"

Pingora info

Pingora version: 0.1.0 Rust version: cargo 1.78.0-nightly (194a60b29 2024-02-21) Operating system version: Pop!_OS 22.04 LTS

Steps to reproduce

1. In terminal 1, run the code above
2. In terminal 2, use curl to launch the request

   curl -v 127.0.0.1:8080

Expected results

1. "Entered upstream_request_filter" should be outputted in terminal 1.
2. The response status code in curl should be 200.

Observed results

1. "Entered upstream_request_filter" is not outputted in terminal 1.
2. The response in curl detail is 502.

Additional context

No

[shenyisyn]

same question

[cxw620]

You may add tracing_subscriber for more logs.

See here, L164, you may check if get_http_session returns Ok, or upstream_request_filter will be called with no doubt when proxy_to_h1_upstream or proxy_to_h2_upstream;

https://github.com/cloudflare/pingora/blob/45791f63455267e41191e03d8895704fe59f7b98/pingora-proxy/src/lib.rs#L150-L223

[fengxsong]

try RUST_LOG=TRACE cargo run xxx for more verbose logging.

[eaufavor]

"Entered upstream_request_filter" should be outputed in terminal 1.

It seems the proxy returned 502 which suggests that the connection to the origin might not be established in the place. The upstream_request_filter will only be called after the connection is established.

The request header in curl detail should be "Host: one.one.one.one"

Regardless of the issue above, the proxy won't change curl's output because the output just reflects what curl sends to the proxy.

[drcaramelsyrup]

@neodes-h : since it looks like your question has been answered, I'll close this issue out. Feel free to reopen if you still have questions on the topic.

If you read further in the quick start guide, you'll notice that we cover why you might be seeing a 502 occasionally with the round-robin LB (in the health checker section). As discussed above, if we fail to connect to the upstream, upstream_request_filter won't be called. (You may be interested in adding more logging in the fail_to_connect phase to confirm for yourself.)