The authority header is not stable across invocations of self.get_http_request_header() and the related variants

[SvetlinZarev]

Summary:

The authority header is not stable across invocations of self.get_http_request_header() and the related variants. I was not able to reproduce the issue with GET requests, but is very easily reproducible with POST requests with a body.

NB: This is the same setup as in #54

MCVE

[package]
name = "wasm-mcve"
version = "0.1.0"
authors = ["Svetlin Zarev"]
edition = "2018"

[lib]
crate-type = ["cdylib"]

[profile.release]
opt-level = 2
lto = "fat"
codegen-units = 1

[dependencies]
proxy-wasm = { path = "/Users/svetlin/git/oss/proxy-wasm-rust-sdk" }
log = "0.4"

use std::time::Duration;
use proxy_wasm::traits::{Context, HttpContext};
use proxy_wasm::types::Action;

const HEADER_MARKER: &str = "x-wasm-marker";
const HEADER_CONNECTION: &str = "connection";
const HEADER_CONTENT_TYPE: &str = "content-type";
const HEADER_AUTHORITY: &str = ":authority";
const HEADER_HTTP_METHOD: &str = ":method";
const HEADER_PATH: &str = ":path";

const HTTP_METHOD_GET: &str = "GET";

const CONNECTION_CLOSE: &str = "close";
const CONTENT_TYPE_TEXT_PLAIN: &str = "text/plain";

const A_CLUSTER: &str = "google";
const A_AUTHORITY: &str = "www.google.com";

const B_CLUSTER: &str = "bing";
const B_AUTHORITY: &str = "www.bing.com";

const DEFAULT_TIMEOUT: Duration = Duration::from_secs(5);


#[no_mangle]
pub fn _start() {
    proxy_wasm::set_log_level(proxy_wasm::types::LogLevel::Trace);
    proxy_wasm::set_http_context(|_, _| Box::new(Plugin::new()));
}

#[derive(Debug, Copy, Clone, Eq, PartialEq)]
enum Response {
    None,
    First,
    Second,
}

struct Plugin {
    response: Response,
}

impl Plugin {
    fn new() -> Plugin {
        Plugin { response: Response::None }
    }

    #[inline]
    fn send_internal_server_error(&self) {
        log::error!("Sending internal server error...");
        self.send_http_response(
            500,
            vec![
                (HEADER_CONTENT_TYPE, CONTENT_TYPE_TEXT_PLAIN),
                (HEADER_CONNECTION, CONNECTION_CLOSE),
            ],
            Some("internal server error".as_bytes()),
        );
    }

    fn on_first(&mut self) {
        log::error!("> on_first");

        self.add_http_request_header(HEADER_MARKER, "on-first");

        log::error!("Dispatching HTTP request to cluster B...");
        let token = self.dispatch_http_call(
            B_CLUSTER,
            vec![
                (HEADER_AUTHORITY, B_AUTHORITY),
                (HEADER_HTTP_METHOD, HTTP_METHOD_GET),
                (HEADER_PATH, "/"),
            ], None,
            vec![],
            DEFAULT_TIMEOUT,
        );

        match token {
            Err(e) => {
                log::error!("Cannot dispatch call to cluster B: {:?}", e);
                self.send_internal_server_error();
            }

            Ok(_) => {
                log::error!("Call to cluster B dispatched");
                self.response = Response::Second;
            }
        }
    }

    fn on_second(&mut self) {
        log::error!("> on_second");

        self.add_http_request_header(HEADER_MARKER, "on-second");

        log::error!("Resuming original HTTP request...");
        self.resume_http_request();
        log::error!("Original HTTP request resumed");
    }
}

impl Context for Plugin {
    fn on_http_call_response(&mut self, _token_id: u32, _num_headers: usize, _body_size: usize, _num_trailers: usize) {
        log::error!("> on_http_call_response");

        let method = self.get_http_request_header(HEADER_HTTP_METHOD);
        let authority = self.get_http_request_header(HEADER_AUTHORITY);
        log::error!("Method: {:?}; Authority: {:?}", method, authority);

        let token = std::mem::replace(&mut self.response, Response::None);
        match token {
            Response::None => {
                log::error!("Unexpected http call response callback!");
                self.send_internal_server_error();
                return;
            }

            Response::First => {
                self.on_first();
            }

            Response::Second => {
                self.on_second()
            }
        }
    }
}

impl HttpContext for Plugin {
    fn on_http_request_headers(&mut self, _num_headers: usize) -> Action {
        log::error!("> on_http_request_headers");

        let method = self.get_http_request_header(HEADER_HTTP_METHOD);
        let authority = self.get_http_request_header(HEADER_AUTHORITY);
        log::error!("Method: {:?}; Authority: {:?}", method, authority);

        log::error!("Dispatching HTTP request to cluster A...");
        let token = self.dispatch_http_call(
            A_CLUSTER,
            vec![
                (HEADER_AUTHORITY, A_AUTHORITY),
                (HEADER_HTTP_METHOD, HTTP_METHOD_GET),
                (HEADER_PATH, "/"),
            ], None,
            vec![],
            DEFAULT_TIMEOUT,
        );

        match token {
            Err(e) => {
                log::error!("Cannot dispatch call to cluster A: {:?}", e);
                self.send_internal_server_error();
            }

            Ok(_) => {
                log::error!("Call to cluster A dispatched");
                self.response = Response::First;
            }
        }

        Action::Pause
    }
}

Sample envoy configuration (can be reproduced on istio as well)

static_resources:
  listeners:
  - address:
      socket_address:
        address: 0.0.0.0
        port_value: 15001
    filter_chains:
    - filters:
      - name: envoy.http_connection_manager 
        typed_config:
          "@type": type.googleapis.com/envoy.config.filter.network.http_connection_manager.v2.HttpConnectionManager
          codec_type: auto
          stat_prefix: http
          access_log:
            name: envoy.file_access_log
            typed_config:
              "@type": type.googleapis.com/envoy.config.accesslog.v2.FileAccessLog
              path: /dev/stdout
          route_config:
            name: search_route
            virtual_hosts:
            - name: backend
              domains:
              - "*"
              routes:
              - match:
                  prefix: "/"
                  headers:
                    - name: ":authority"
                      exact_match: "www.google.com"
                route:
                  cluster: google
                  host_rewrite: www.google.com
              - match:
                  prefix: "/"
                  headers:
                    - name: ":authority"
                      exact_match: "www.bing.com"
                route:
                  cluster: bing
                  host_rewrite: www.bing.com
              - match:
                  prefix: "/"
                  headers:
                    - name: ":authority"
                      exact_match: "requestbin"
                route:
                  cluster: requestbin
                  host_rewrite: f85bd0cbc72fec2729a2267267df5a57.m.pipedream.net
          http_filters:
          - name: envoy.filters.http.wasm
            typed_config:
              "@type": type.googleapis.com/envoy.extensions.filters.http.wasm.v3.Wasm
              config:
                name: "wasm_plugin"
                vmConfig:
                  runtime: "envoy.wasm.runtime.v8"
                  allowPrecompiled: true
                  code:
                    local:
                      filename: "/root/plugin.wasm"
                  allow_precompiled: true
          - name: envoy.filters.http.router
            typed_config: {}
  clusters:
  - name: google
    connect_timeout: 10s
    type: logical_dns
    dns_lookup_family: V4_ONLY
    lb_policy: round_robin
    load_assignment:
      cluster_name: google
      endpoints:
      - lb_endpoints:
        - endpoint:
            address:
              socket_address:
                address: www.google.com
                port_value: 443
    transport_socket:
      name: envoy.transport_sockets.tls
      typed_config:
        "@type": type.googleapis.com/envoy.extensions.transport_sockets.tls.v3.UpstreamTlsContext
        sni: www.google.com
  - name: bing
    connect_timeout: 10s
    type: logical_dns
    dns_lookup_family: V4_ONLY
    lb_policy: round_robin
    load_assignment:
      cluster_name: bing
      endpoints:
      - lb_endpoints:
        - endpoint:
            address:
              socket_address:
                address: www.bing.com
                port_value: 443
    transport_socket:
      name: envoy.transport_sockets.tls
      typed_config:
        "@type": type.googleapis.com/envoy.extensions.transport_sockets.tls.v3.UpstreamTlsContext
        sni: www.bing.com
  - name: requestbin
    connect_timeout: 10s
    type: logical_dns
    dns_lookup_family: V4_ONLY
    lb_policy: round_robin
    load_assignment:
      cluster_name: requestbin
      endpoints:
      - lb_endpoints:
        - endpoint:
            address:
              socket_address:
                address: f85bd0cbc72fec2729a2267267df5a57.m.pipedream.net
                port_value: 443
    transport_socket:
      name: envoy.transport_sockets.tls
      typed_config:
        "@type": type.googleapis.com/envoy.extensions.transport_sockets.tls.v3.UpstreamTlsContext
        sni: f85bd0cbc72fec2729a2267267df5a57.m.pipedream.net
admin:
  access_log_path: "/dev/stdout"
  address:
    socket_address:
      address: 0.0.0.0
      port_value: 15000

As the requestbin is not publicly visible you'll have to create your own and update the configuration accordingly.

Steps to reproduce

I'm reproducing it in a docker image (thus the localhost address), but can be done also on k8s with istio.

Make a POST request WITH a body (maybe related to #54 ).

curl -kvvv -w "\r\n" -X POST  --header "Host: requestbin" localhost:15001 --data '{}'

Expectation

On envoy side

I expect to see in the logs that the authority header remains the same across invocations of self.get_http_request_header() . Example:

[2020-11-19T18:52:05.366Z] "POST / HTTP/1.1" 200 - 2 19 200 199 "-" "curl/7.64.1" "ab455f56-392d-4983-bc16-df6534cdf0cc" 
...
/wasm/context.cc:1113] wasm log wasm_plugin : > on_http_request_headers
**[2020-11-19 19:03:06.527][13][error][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1113] wasm log wasm_plugin : Method: Some("POST"); Authority: Some("requestbin")**
...
/wasm/context.cc:1113] wasm log wasm_plugin : > on_http_call_response
**[2020-11-19 19:03:06.727][13][error][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1113] wasm log wasm_plugin : Method: Some("POST"); Authority: Some("requestbin")**
[2020-11-19 19:03:06.727][13][error][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1113] wasm log wasm_plugin : > on_first
...
/wasm/context.cc:1113] wasm log wasm_plugin : > on_http_call_response
**[2020-11-19 19:03:07.104][13][error][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1113] wasm log wasm_plugin : Method: Some("POST"); Authority: Some("requestbin")**
[2020-11-19 19:03:07.104][13][error][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1113] wasm log wasm_plugin : > on_second
...

What actually happens

On envoy side

The authority header is changed from the incoming one (e.g. requestbin) to the one specified in the route configuration (host rewrite) (e.g. f85bd0cbc72fec2729a2267267df5a57.m.pipedream.net)

[2020-11-19T19:05:04.093Z] "POST / HTTP/1.1" 200 - 2 19 550 548 "-" "curl/7.64.1" "142a8042-8c26-4636-8697-7f3b843a5cd5" 
...
/wasm/context.cc:1113] wasm log wasm_plugin : > on_http_request_headers
**[2020-11-19 19:05:15.526][12][error][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1113] wasm log wasm_plugin : Method: Some("POST"); Authority: Some("requestbin")**
...
/wasm/context.cc:1113] wasm log wasm_plugin : > on_http_call_response
**[2020-11-19 19:05:15.624][12][error][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1113] wasm log wasm_plugin : Method: Some("POST"); Authority: Some("f85bd0cbc72fec2729a2267267df5a57.m.pipedream.net")**
[2020-11-19 19:05:15.624][12][error][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1113] wasm log wasm_plugin : > on_first
...

Without a request body

If you make the same request but without the body, or make a GET request

curl -kvvv -w "\r\n" -X POST  --header "Host: requestbin" localhost:15001 --data ''
curl -kvvv -w "\r\n" -X GET  --header "Host: requestbin" localhost:15001

Then the issue is NOT reproducible and works as expected 100% of the trials

[PiotrSikora]

Are you testing with latest Envoy? I think you might be hitting the same issue as we discussed in #43, i.e. request body is being processed even when headers are paused. This was fixed a few days ago in proxy-wasm/proxy-wasm-cpp-host#95 and envoyproxy/envoy#13840.

With those fixes, request headers should be stable until you resume request processing. However, since those headers can be modified by other Proxy-Wasm plugins and/or native extensions in the proxy, you might see different headers in later callbacks.

Is that reasonable or do you need to always see the original request headers, and not the headers sent upstream?