Skip to content

It's not possible to issue a second http call  #40

New issue
New issue
Closed
#56
Closed
It's not possible to issue a second http call #40
#56
@SvetlinZarev

Description

@SvetlinZarev
SvetlinZarev
opened on Oct 25, 2020

Hi,

Currently it's not possible to issue another http call from Context::on_http_call_response. Is this intentional ? If it is how is one supposed to make several http calls, for example fetch an oauth token, call another service with it, then resume the request ?

The error is:

[2020-10-25 11:04:04.792][12][critical][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1018] wasm log: panicked at 'already borrowed: BorrowMutError', /Users/svetlin/.cargo/registry/src/github.tiyicn.workers.dev-1ecc6299db9ec823/proxy-wasm-0.1.2/src/dispatcher.rs:137:14

I believe the error is caused because the dispatcher tries to borrow the callouts for a second time when registering the second http call.

The first borrow occurs when calling the on_http_call_response callback. The duration of the borrow lasts for the whole if let Some() body.

Given that the context_id is Copy, this method can be modified like that:

{
        let context_id = match self.callouts.borrow_mut().remove(&token_id) {
            Some(id) => id,
            None => panic!("invalid token_id")
        };

        if let Some(http_stream) = self.http_streams.borrow_mut().get_mut(&context_id) {
            self.active_id.set(context_id);
            hostcalls::set_effective_context(context_id).unwrap();
            http_stream.on_http_call_response(token_id, num_headers, body_size, num_trailers)
        } else if let Some(stream) = self.streams.borrow_mut().get_mut(&context_id) {
            self.active_id.set(context_id);
            hostcalls::set_effective_context(context_id).unwrap();
            stream.on_http_call_response(token_id, num_headers, body_size, num_trailers)
        } else if let Some(root) = self.roots.borrow_mut().get_mut(&context_id) {
            self.active_id.set(context_id);
            hostcalls::set_effective_context(context_id).unwrap();
            root.on_http_call_response(token_id, num_headers, body_size, num_trailers)
        }
    }

Thus eliminating the borrow on the callouts member, which resolves the issue.

What do you think ?

Activity

SvetlinZarev

SvetlinZarev commented on Nov 9, 2020

@SvetlinZarev
SvetlinZarev
on Nov 9, 2020 · edited by SvetlinZarev
Author

Reproducible example:

Cargo.toml:

[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 = "0.1.2"
log = "0.4"

lib.rs:

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

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");

        log::info!("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::info!("> on_second");

        log::info!("Resuming original HTTP request...");
        self.resume_http_request();
        log::info!("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");
        log::error!("Call response headers: {:?}", self.get_http_call_response_headers());

        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::info!("> on_http_request_headers");

        log::info!("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
    }
}

envoy config:

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: "www.yandex.ru"
                route:
                  cluster: yandex
                  host_rewrite: www.yandex.ru
          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: yandex
    connect_timeout: 10s
    type: logical_dns
    dns_lookup_family: V4_ONLY
    lb_policy: round_robin
    load_assignment:
      cluster_name: yandex
      endpoints:
      - lb_endpoints:
        - endpoint:
            address:
              socket_address:
                address: www.yandex.ru
                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.yandex.ru
admin:
  access_log_path: "/dev/stdout"
  address:
    socket_address:
      address: 0.0.0.0
      port_value: 15000

Make an http request to the proxy:

 curl -vvv -w "\r\n" --header "Host: www.yandex.ru" localhost:15001

As a result envoy crashes due to multiple mutable borrows:

[2020-11-09 08:58:22.976][13][info][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1107] wasm log wasm_plugin : > on_http_request_headers
[2020-11-09 08:58:22.976][13][info][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1107] wasm log wasm_plugin : Dispatching HTTP request to cluster A...
[2020-11-09 08:58:22.977][13][error][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1113] wasm log wasm_plugin : Call to cluster A dispatched
[2020-11-09 08:58:23.137][13][error][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1113] wasm log wasm_plugin : > on_http_call_response
[2020-11-09 08:58:23.138][13][error][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1113] wasm log wasm_plugin : Call response headers: [...]
[2020-11-09 08:58:23.138][13][error][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1113] wasm log wasm_plugin : > on_first
[2020-11-09 08:58:23.138][13][info][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1107] wasm log wasm_plugin : Dispatching HTTP request to cluster B...
[2020-11-09 08:58:23.139][13][critical][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1116] wasm log wasm_plugin : panicked at 'already borrowed: BorrowMutError', /Users/svetlin/.cargo/registry/src/github.tiyicn.workers.dev-1ecc6299db9ec823/proxy-wasm-0.1.2/src/dispatcher.rs:137:14
[2020-11-09 08:58:23.151][13][critical][main] [external/envoy/source/exe/terminate_handler.cc:13] std::terminate called! (possible uncaught exception, see trace)
[2020-11-09 08:58:23.152][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:91] Backtrace (use tools/stack_decode.py to get line numbers):
[2020-11-09 08:58:23.152][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:92] Envoy version: 201124ab4fc06dc051c9aebdb49f1d2197e46f02/1.14.5-dev/Clean/RELEASE/BoringSSL
[2020-11-09 08:58:23.173][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #0: Envoy::TerminateHandler::logOnTerminate()::$_0::operator()() [0x55da91fd7814]
[2020-11-09 08:58:23.187][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:98] #1: [0x55da91fd7729]
[2020-11-09 08:58:23.201][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #2: std::__terminate() [0x55da9259d5a3]
[2020-11-09 08:58:23.215][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #3: std::__1::__function::__func<>::operator()() [0x55da90d9dffb]
[2020-11-09 08:58:23.229][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #4: Envoy::Extensions::Common::Wasm::Context::onHttpCallResponse() [0x55da90d627ea]
[2020-11-09 08:58:23.244][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #5: Envoy::Extensions::Common::Wasm::Context::onHttpCallSuccess() [0x55da90d64c62]
[2020-11-09 08:58:23.258][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #6: Envoy::Http::AsyncRequestImpl::onComplete() [0x55da91d0b17f]
[2020-11-09 08:58:23.272][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #7: Envoy::Http::AsyncStreamImpl::encodeData() [0x55da91d0ab33]
[2020-11-09 08:58:23.287][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #8: Envoy::Router::UpstreamRequest::decodeData() [0x55da91d1d2ae]
[2020-11-09 08:58:23.300][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #9: Envoy::Http::ResponseDecoderWrapper::decodeData() [0x55da91c89adb]
[2020-11-09 08:58:23.300][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #10: Envoy::Http::ResponseDecoderWrapper::decodeData() [0x55da91c89adb]
[2020-11-09 08:58:23.314][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #11: Envoy::Http::Http1::ClientConnectionImpl::onMessageComplete() [0x55da91d928a1]
[2020-11-09 08:58:23.328][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #12: Envoy::Http::Http1::ConnectionImpl::onMessageCompleteBase() [0x55da91d8feab]
[2020-11-09 08:58:23.342][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #13: Envoy::Http::Http1::ConnectionImpl::$_8::__invoke() [0x55da91d9461d]
[2020-11-09 08:58:23.356][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #14: http_parser_execute [0x55da91f5ea6c]
[2020-11-09 08:58:23.370][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #15: Envoy::Http::Http1::ConnectionImpl::dispatchSlice() [0x55da91d8f1da]
[2020-11-09 08:58:23.383][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #16: Envoy::Http::Http1::ConnectionImpl::dispatch() [0x55da91d8ef4f]
[2020-11-09 08:58:23.397][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #17: Envoy::Http::CodecClient::onData() [0x55da91cf9738]
[2020-11-09 08:58:23.411][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #18: Envoy::Http::CodecClient::CodecReadFilter::onData() [0x55da91cfa48d]
[2020-11-09 08:58:23.424][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #19: Envoy::Network::FilterManagerImpl::onContinueReading() [0x55da91b18d33]
[2020-11-09 08:58:23.439][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #20: Envoy::Network::ConnectionImpl::onReadReady() [0x55da91b14e75]
[2020-11-09 08:58:23.453][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #21: Envoy::Network::ConnectionImpl::onFileEvent() [0x55da91b141cd]
[2020-11-09 08:58:23.468][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #22: Envoy::Event::FileEventImpl::assignEvents()::$_0::__invoke() [0x55da91b0f1f6]
[2020-11-09 08:58:23.482][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #23: event_process_active_single_queue [0x55da91f5868b]
[2020-11-09 08:58:23.498][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #24: event_base_loop [0x55da91f56f1e]
[2020-11-09 08:58:23.513][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #25: Envoy::Server::WorkerImpl::threadRoutine() [0x55da91b03034]
[2020-11-09 08:58:23.528][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #26: Envoy::Thread::ThreadImplPosix::ThreadImplPosix()::$_0::__invoke() [0x55da9200d9e3]
[2020-11-09 08:58:23.528][13][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:96] #27: start_thread [0x7f83e33eafa3]
PiotrSikora

PiotrSikora commented on Nov 14, 2020

@PiotrSikora
PiotrSikora
on Nov 14, 2020
Member

Thanks for the report and reproducer! I think your patch is correct. Could you send a PR?

SvetlinZarev
mentioned this on Nov 19, 2020
PiotrSikora

PiotrSikora commented on Nov 19, 2020

@PiotrSikora
PiotrSikora
on Nov 19, 2020
Member

Hi @SvetlinZarev, I see that you pushed fix to your fork (https://github.com/SvetlinZarev/proxy-wasm-rust-sdk/commit/5190a0437c9c96ec378839598793ea98fc6769e8), but you didn't open a PR. Could you do that or are you still working on it?

SvetlinZarev

SvetlinZarev commented on Nov 19, 2020

@SvetlinZarev
SvetlinZarev
on Nov 19, 2020
Author

Unfortunately I'm struggling with the OSS process at my place :( (due to the required CLA).

PiotrSikora

PiotrSikora commented on Nov 19, 2020

@PiotrSikora
PiotrSikora
on Nov 19, 2020
Member

Do you have any ETA or is that unlikely to happen at all?

PiotrSikora
mentioned this on Dec 4, 2020
PiotrSikora
closed this as completedin #56on Dec 4, 2020
PiotrSikora
added a commit that references this issue on Jul 4, 2023

Deletes unimplemented vNEXT doc. (proxy-wasm#40)

86719f5
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

      Development

      Participants

      @PiotrSikora@SvetlinZarev

      Issue actions
        It's not possible to issue a second http call · Issue #40 · proxy-wasm/proxy-wasm-rust-sdk