panicked at 'already borrowed: BorrowMutError', proxy-wasm-0.1.3/src/dispatcher.rs:326:54`

[lahabana]

Firstly I'm very noob on both Rust and Envoy so take all observations/conclusions with a grain of salt :)

I have very simple function that does:

use std::time::Duration;

use proxy_wasm::traits::{Context, HttpContext};
use proxy_wasm::types::{Action, LogLevel};

#[no_mangle]
pub fn _start() {
    proxy_wasm::set_log_level(LogLevel::Trace);
    proxy_wasm::set_http_context(|_, _| -> Box<dyn HttpContext> { Box::new(HttpActivator) });
}

struct HttpActivator;

impl HttpContext for HttpActivator {
    fn on_http_request_headers(&mut self, _: usize) -> Action {
        let method = self.get_http_request_header(":method").unwrap_or(String::from("GET"));
        let path = self.get_http_request_header(":path").unwrap_or(String::from("/"));
        let authority = self.get_http_request_header(":authority").unwrap_or(String::from(""));
        match self.dispatch_http_call(
            "myservice",
            vec![
                (":method", "POST"),
                (":path", "/request"),
            ],
            Some(format!(r#"{{"method": "{}", "path": "{}", "authority": "{}"}}"#, method, path, authority).as_bytes()),
            vec![],
            Duration::from_secs(5),
        ) {
            Ok(_) => {
                Action::Pause
            }
            Err(_e) => {
                Action::Continue
            }
        }
    }
}

impl Context for HttpActivator {
    fn on_http_call_response(&mut self, _: u32, _: usize, body_size: usize, _: usize) {
         self.resume_http_request()
    }
}

I'm using a docker image for envoy: istio/proxyv2:1.5.0 it embeds envoy: 73f240a29bece92a8882a36893ccce07b4a54664/1.13.1-dev/Clean/RELEASE/BoringSSL.

When I run this envoy panics with: panicked at 'already borrowed: BorrowMutError', proxy-wasm-0.1.3/src/dispatcher.rs:326:54

Full Stacktrace:

[2021-01-05 19:40:10.616][14][critical][wasm] [external/envoy/source/extensions/common/wasm/context.cc:1086] wasm log envoy-wasm-activator envoy-wasm-activator : panicked at 'already borrowed: BorrowMutError', proxy-wasm-0.1.3/src/dispatcher.rs:326:54
[2021-01-05 19:40:10.616][14][critical][main] [external/envoy/source/exe/terminate_handler.cc:13] std::terminate called! (possible uncaught exception, see trace)
[2021-01-05 19:40:10.617][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:70] Backtrace (use tools/stack_decode.py to get line numbers):
[2021-01-05 19:40:10.617][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:71] Envoy version: 73f240a29bece92a8882a36893ccce07b4a54664/1.13.1-dev/Clean/RELEASE/BoringSSL
[2021-01-05 19:40:10.625][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #0: Envoy::TerminateHandler::logOnTerminate()::$_0::operator()() [0x55792fccedae]
[2021-01-05 19:40:10.633][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:77] #1: [0x55792fccecb9]
[2021-01-05 19:40:10.644][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #2: std::__terminate() [0x557930231a73]
[2021-01-05 19:40:10.657][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #3: Envoy::Extensions::Common::Wasm::Context::onResponseHeaders() [0x55792eace9b7]
[2021-01-05 19:40:10.667][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #4: Envoy::Extensions::Common::Wasm::Context::encodeHeaders() [0x55792ead0dff]
[2021-01-05 19:40:10.675][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #5: Envoy::Http::ConnectionManagerImpl::ActiveStream::encodeHeaders() [0x55792fa5a7a8]
[2021-01-05 19:40:10.683][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #6: Envoy::Http::Utility::sendLocalReply() [0x55792fb06001]
[2021-01-05 19:40:10.691][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #7: Envoy::Http::ConnectionManagerImpl::ActiveStream::sendLocalReply() [0x55792fa55f56]
[2021-01-05 19:40:10.699][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #8: Envoy::Http::ConnectionManagerImpl::ActiveStreamDecoderFilter::sendLocalReply() [0x55792fa5f5c4]
[2021-01-05 19:40:10.706][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #9: Envoy::Router::Filter::decodeHeaders() [0x55792f9f7289]
[2021-01-05 19:40:10.714][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #10: Envoy::Http::ConnectionManagerImpl::ActiveStream::decodeHeaders() [0x55792fa583c9]
[2021-01-05 19:40:10.722][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #11: Envoy::Http::ConnectionManagerImpl::ActiveStreamFilterBase::commonContinue() [0x55792fa5cb7e]
[2021-01-05 19:40:10.730][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #12: Envoy::Extensions::Common::Wasm::Exports::continue_request() [0x55792eaddbcb]
[2021-01-05 19:40:10.737][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #13: Envoy::Extensions::Common::Wasm::V8::V8::registerHostFunctionImpl<>()::{lambda()#1}::operator()() [0x55792eb0a99d]
[2021-01-05 19:40:10.745][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #14: Envoy::Extensions::Common::Wasm::V8::V8::registerHostFunctionImpl<>()::{lambda()#1}::__invoke() [0x55792eb0a8b7]
[2021-01-05 19:40:10.753][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #15: wasm::FuncData::v8_callback() [0x55792eb1c34e]
[2021-01-05 19:40:10.754][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:77] #16: [0x3248a417a94c]
[2021-01-05 19:40:10.754][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:77] #17: [0x3248a4135024]
[2021-01-05 19:40:10.754][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:77] #18: [0x3248a41306dd]
[2021-01-05 19:40:10.754][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:77] #19: [0x3248a414be9b]
[2021-01-05 19:40:10.755][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:77] #20: [0x3248a415011e]
[2021-01-05 19:40:10.755][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:77] #21: [0x49600083379]
[2021-01-05 19:40:10.763][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #22: v8::internal::Execution::CallWasm() [0x55792ebf2b93]
[2021-01-05 19:40:10.771][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #23: wasm::Func::call() [0x55792eb1b762]
[2021-01-05 19:40:10.779][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #24: Envoy::Extensions::Common::Wasm::V8::V8::getModuleFunctionImpl<>()::{lambda()#1}::operator()() [0x55792eb02f42]
[2021-01-05 19:40:10.787][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #25: std::__1::__function::__func<>::operator()() [0x55792eb02d5b]
[2021-01-05 19:40:10.795][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #26: Envoy::Extensions::Common::Wasm::Context::onHttpCallResponse() [0x55792eacecba]
[2021-01-05 19:40:10.802][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #27: Envoy::Extensions::Common::Wasm::Context::onHttpCallSuccess() [0x55792ead1022]
[2021-01-05 19:40:10.811][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #28: Envoy::Http::AsyncRequestImpl::onComplete() [0x55792f9f1b6c]
[2021-01-05 19:40:10.826][14][critical][backtrace] [bazel-out/k8-opt/bin/external/envoy/source/server/_virtual_includes/backtrace_lib/server/backtrace.h:75] #29: Envoy::Http::AsyncStreamImpl::encodeData() [0x55792f9f1532]

The service on the other side does get the request and returns a successful status with a body.

Looking at the code:

    fn on_http_response_headers(&self, context_id: u32, num_headers: usize) -> Action {
        if let Some(http_stream) = self.http_streams.borrow_mut().get_mut(&context_id) {
            self.active_id.set(context_id);
            http_stream.on_http_response_headers(num_headers)
        } else {
            panic!("invalid context_id")
        }
    }

This might be unrelated but it does seems that http_streams shouldn't be mutually borrowed and having 2 inflight http requests creates 2 different httpContext and may produce a scenario where the http_streams is borrowed twice.
If that is the case using interior mutability might save us here.

We'd be able to do:

if let Some(http_stream) = self.http_streams.get(&context_id).borrow_mut() {...}

To do this I guess using Rc<RefCell<dyn HttpContext>> should work but this also implies changing the function defs New[...]Context to return something like RefCell<dyn HttpContext> which is an api breaking change.

Considering I'm not super knowledgeable in Rust I wanted to get an opinion before working on a PR.

• Are these observations correct?
• Is there a simpler way to do this to avoid breaking the api (I'm thinking some rust way to convert a Box to a RefCell which seems odd)?

If not I'll try to fix this.

[PiotrSikora]

Please try using a more recent version of Envoy, istio/proxyv2:1.8.1 should have all fixes for Proxy-Wasm.

See #43 for some background.

[lahabana]

Tried with 1.8.1 and it worked thanks!

Btw for my own rust education was the workaround correct if this were an issue on this side (switching to interior mutability with Rc<RefCell<>>)?

Thanks for the very quick reply

[parasyte]

Btw for my own rust education was the workaround correct if this were an issue on this side (switching to interior mutability with Rc<RefCell<>>)?

Unfortunately not. The code was already using RefCell<T> which has runtime borrow-checking. Rc can add reference counting, but it cannot change the behavior of runtime borrow-checking with reentrant calls.