proxy-wasm-rust-sdk
proxy-wasm-rust-sdk copied to clipboard
proxy-wasm
how to fix unexpected status: 12 panic by hostcalls.rs:851
Hello, I am having trouble using dispatch_grpc_call, it is a proxy filter plugin for apisix and named it insignia_validate_user_context, it return error such as below
apisix-1 | 2024/08/26 19:03:57 [emerg] 55#55: *2114 panicked at /Users/xanonx/.cargo/registry/src/index.crates.io-6f17d22bba15001f/proxy-wasm-0.2.2/src/hostcalls.rs:851:23:
apisix-1 | unexpected status: 12, client: 192.168.65.1, server: _, request: "POST /post HTTP/1.1", host: "testxx.127.0.0.1.sslip.io:9080"
apisix-1 | 2024/08/26 19:03:57 [error] 55#55: failed to call function: wasm trap: wasm `unreachable` instruction executed
apisix-1 | wasm backtrace:
apisix-1 | 0: 0x9acbf - insignia_validate_user_context.wasm!__rust_start_panic
apisix-1 | 1: 0x9ac8d - insignia_validate_user_context.wasm!rust_panic
apisix-1 | 2: 0x9ac7f - insignia_validate_user_context.wasm!std::panicking::rust_panic_with_hook::h47bd3d747ed79dc3
apisix-1 | 3: 0x9a273 - insignia_validate_user_context.wasm!std::panicking::begin_panic_handler::{{closure}}::hec06b0d4affd51e6
apisix-1 | 4: 0x9a1da - insignia_validate_user_context.wasm!std::sys_common::backtrace::__rust_end_short_backtrace::h36214b32c979e4c1
apisix-1 | 5: 0x9a912 - insignia_validate_user_context.wasm!rust_begin_unwind
apisix-1 | 6: 0x9b4e2 - insignia_validate_user_context.wasm!core::panicking::panic_fmt::hb859252f4b513814
apisix-1 | 7: 0x65c03 - insignia_validate_user_context.wasm!proxy_wasm::hostcalls::dispatch_grpc_call::h7d02d9c78bdfc88e
apisix-1 | 8: 0x25508 - insignia_validate_user_context.wasm!proxy_wasm::traits::Context::dispatch_grpc_call::hdb889c883890f06b
apisix-1 | 9: 0xea30 - insignia_validate_user_context.wasm!<insignia_validate_user_context::CustomHttpContext as proxy_wasm::traits::HttpContext>::on_http_request_headers::h1860c4878f75bca7
apisix-1 | 10: 0x8f487 - insignia_validate_user_context.wasm!proxy_wasm::dispatcher::Dispatcher::on_http_request_headers::h86f58ce9d4d89dee
apisix-1 | 11: 0x943cb - insignia_validate_user_context.wasm!proxy_wasm::dispatcher::proxy_on_request_headers::{{closure}}::haeb52924730c9884
apisix-1 | 12: 0x875fa - insignia_validate_user_context.wasm!std::thread::local::LocalKey<T>::try_with::h86eb214de4bf4a59
apisix-1 | 13: 0x87443 - insignia_validate_user_context.wasm!std::thread::local::LocalKey<T>::with::h62475dc3588edaaa
apisix-1 | 14: 0x94348 - insignia_validate_user_context.wasm!proxy_on_request_headers
apisix-1 | note: using the `WASMTIME_BACKTRACE_DETAILS=1` environment variable to may show more debugging information
apisix-1 |
apisix-1 | 2024/08/26 19:03:57 [error] 55#55: *2114 [lua] wasm.lua:85: phase_func(): insignia-validate-user-context: failed to run wasm plugin: failed to run proxy_on_http_request_headers, client: 192.168.65.1, server: _, request: "POST /post HTTP/1.1", host: "testxx.127.0.0.1.sslip.io:9080"
apisix-1 | 2024/08/26 19:03:57 [warn] 55#55: *2114 [lua] plugin.lua:1160: run_plugin(): insignia-validate-user-context exits with http status code 503, client: 192.168.65.1, server: _, request: "POST /post HTTP/1.1", host: "testxx.127.0.0.1.sslip.io:9080"
apisix-1 | 2024/08/26 19:03:57 [emerg] 55#55: *2114 panicked at /Users/xanonx/.cargo/registry/src/index.crates.io-6f17d22bba15001f/proxy-wasm-0.2.2/src/dispatcher.rs:371:54:
apisix-1 | already borrowed: BorrowMutError, client: 192.168.65.1, server: _, request: "POST /post HTTP/1.1", host: "testxx.127.0.0.1.sslip.io:9080"
apisix-1 | 2024/08/26 19:03:57 [error] 55#55: failed to call function: wasm trap: wasm `unreachable` instruction executed
apisix-1 | wasm backtrace:
apisix-1 | 0: 0x9acbf - insignia_validate_user_context.wasm!__rust_start_panic
apisix-1 | 1: 0x9ac8d - insignia_validate_user_context.wasm!rust_panic
apisix-1 | 2: 0x9ac7f - insignia_validate_user_context.wasm!std::panicking::rust_panic_with_hook::h47bd3d747ed79dc3
apisix-1 | 3: 0x9a273 - insignia_validate_user_context.wasm!std::panicking::begin_panic_handler::{{closure}}::hec06b0d4affd51e6
apisix-1 | 4: 0x9a1da - insignia_validate_user_context.wasm!std::sys_common::backtrace::__rust_end_short_backtrace::h36214b32c979e4c1
apisix-1 | 5: 0x9a912 - insignia_validate_user_context.wasm!rust_begin_unwind
apisix-1 | 6: 0x9b4e2 - insignia_validate_user_context.wasm!core::panicking::panic_fmt::hb859252f4b513814
apisix-1 | 7: 0xa0708 - insignia_validate_user_context.wasm!core::cell::panic_already_borrowed::hf06b3e0f393df82e
apisix-1 | 8: 0x5903d - insignia_validate_user_context.wasm!core::cell::RefCell<T>::borrow_mut::hdb92766c3654dce0
apisix-1 | 9: 0x8f87b - insignia_validate_user_context.wasm!proxy_wasm::dispatcher::Dispatcher::on_http_response_headers::h3e356ebf9d7bd883
apisix-1 | 10: 0x94728 - insignia_validate_user_context.wasm!proxy_wasm::dispatcher::proxy_on_response_headers::{{closure}}::h05a391ebba8d6c7e
apisix-1 | 11: 0x8824e - insignia_validate_user_context.wasm!std::thread::local::LocalKey<T>::try_with::h1fb8355bb0d72dff
apisix-1 | 12: 0x88097 - insignia_validate_user_context.wasm!std::thread::local::LocalKey<T>::with::h8201319d49f70a5f
apisix-1 | 13: 0x946a5 - insignia_validate_user_context.wasm!proxy_on_response_headers
apisix-1 | note: using the `WASMTIME_BACKTRACE_DETAILS=1` environment variable to may show more debugging information
apisix-1 |
apisix-1 | 2024/08/26 19:03:57 [error] 55#55: *2114 [lua] wasm.lua:121: phase_func(): insignia-validate-user-context: failed to run wasm plugin: failed to run proxy_on_http_response_headers, client: 192.168.65.1, server: _, request: "POST /post HTTP/1.1", host: "testxx.127.0.0.1.sslip.io:9080"
apisix-1 | 2024/08/26 19:03:57 [emerg] 55#55: panicked at /Users/xanonx/.cargo/registry/src/index.crates.io-6f17d22bba15001f/proxy-wasm-0.2.2/src/dispatcher.rs:209:54:
apisix-1 | already borrowed: BorrowMutError
apisix-1 | 2024/08/26 19:03:57 [error] 55#55: failed to call function: wasm trap: wasm `unreachable` instruction executed
apisix-1 | wasm backtrace:
apisix-1 | 0: 0x9acbf - insignia_validate_user_context.wasm!__rust_start_panic
apisix-1 | 1: 0x9ac8d - insignia_validate_user_context.wasm!rust_panic
apisix-1 | 2: 0x9ac7f - insignia_validate_user_context.wasm!std::panicking::rust_panic_with_hook::h47bd3d747ed79dc3
apisix-1 | 3: 0x9a273 - insignia_validate_user_context.wasm!std::panicking::begin_panic_handler::{{closure}}::hec06b0d4affd51e6
apisix-1 | 4: 0x9a1da - insignia_validate_user_context.wasm!std::sys_common::backtrace::__rust_end_short_backtrace::h36214b32c979e4c1
apisix-1 | 5: 0x9a912 - insignia_validate_user_context.wasm!rust_begin_unwind
apisix-1 | 6: 0x9b4e2 - insignia_validate_user_context.wasm!core::panicking::panic_fmt::hb859252f4b513814
apisix-1 | 7: 0xa0708 - insignia_validate_user_context.wasm!core::cell::panic_already_borrowed::hf06b3e0f393df82e
apisix-1 | 8: 0x5903d - insignia_validate_user_context.wasm!core::cell::RefCell<T>::borrow_mut::hdb92766c3654dce0
apisix-1 | 9: 0x8d97b - insignia_validate_user_context.wasm!proxy_wasm::dispatcher::Dispatcher::on_done::hf43b6ca26aa32b5a
apisix-1 | 10: 0x93881 - insignia_validate_user_context.wasm!proxy_wasm::dispatcher::proxy_on_done::{{closure}}::hda48f7631a71aad6
apisix-1 | 11: 0x8885d - insignia_validate_user_context.wasm!std::thread::local::LocalKey<T>::try_with::h6a5d00a620b901f0
apisix-1 | 12: 0x886c6 - insignia_validate_user_context.wasm!std::thread::local::LocalKey<T>::with::ha212da4897a8841c
apisix-1 | 13: 0x93818 - insignia_validate_user_context.wasm!proxy_on_done
apisix-1 | note: using the `WASMTIME_BACKTRACE_DETAILS=1` environment variable to may show more debugging information
apisix-1 |
apisix-1 | 2024/08/26 19:03:57 [error] 55#55: failed to mark context 2 as done, rc: -1
apisix-1 | 2024/08/26 19:03:57 [emerg] 55#55: panicked at /Users/xanonx/.cargo/registry/src/index.crates.io-6f17d22bba15001f/proxy-wasm-0.2.2/src/dispatcher.rs:239:32:
apisix-1 | already borrowed: BorrowMutError
apisix-1 | 2024/08/26 19:03:57 [error] 55#55: failed to call function: wasm trap: wasm `unreachable` instruction executed
apisix-1 | wasm backtrace:
apisix-1 | 0: 0x9acbf - insignia_validate_user_context.wasm!__rust_start_panic
apisix-1 | 1: 0x9ac8d - insignia_validate_user_context.wasm!rust_panic
apisix-1 | 2: 0x9ac7f - insignia_validate_user_context.wasm!std::panicking::rust_panic_with_hook::h47bd3d747ed79dc3
apisix-1 | 3: 0x9a273 - insignia_validate_user_context.wasm!std::panicking::begin_panic_handler::{{closure}}::hec06b0d4affd51e6
apisix-1 | 4: 0x9a1da - insignia_validate_user_context.wasm!std::sys_common::backtrace::__rust_end_short_backtrace::h36214b32c979e4c1
apisix-1 | 5: 0x9a912 - insignia_validate_user_context.wasm!rust_begin_unwind
apisix-1 | 6: 0x9b4e2 - insignia_validate_user_context.wasm!core::panicking::panic_fmt::hb859252f4b513814
apisix-1 | 7: 0xa0708 - insignia_validate_user_context.wasm!core::cell::panic_already_borrowed::hf06b3e0f393df82e
apisix-1 | 8: 0x5903d - insignia_validate_user_context.wasm!core::cell::RefCell<T>::borrow_mut::hdb92766c3654dce0
apisix-1 | 9: 0x8e172 - insignia_validate_user_context.wasm!proxy_wasm::dispatcher::Dispatcher::on_delete::h7b91e38f0b3259b9
apisix-1 | 10: 0x939fc - insignia_validate_user_context.wasm!proxy_wasm::dispatcher::proxy_on_delete::{{closure}}::h41455db559485fc1
apisix-1 | 11: 0x88412 - insignia_validate_user_context.wasm!std::thread::local::LocalKey<T>::try_with::hd584da9221635bc1
apisix-1 | 12: 0x882ca - insignia_validate_user_context.wasm!std::thread::local::LocalKey<T>::with::h89f94f54af7b8314
apisix-1 | 13: 0x939a2 - insignia_validate_user_context.wasm!proxy_on_delete
apisix-1 | note: using the `WASMTIME_BACKTRACE_DETAILS=1` environment variable to may show more debugging information
apisix-1 |
apisix-1 | 2024/08/26 19:03:57 [error] 55#55: failed to delete context 2, rc: -1
apisix-1 | 192.168.65.1 - - [26/Aug/2024:19:03:57 +0000] testxx.127.0.0.1.sslip.io:9080 "POST /post HTTP/1.1" 503 269 0.000 "-" "vscode-restclient" - - - "http://testxx.127.0.0.1.sslip.io:9080/post"
below is the proxy filter code
use std::time::Duration;
use std::collections::HashMap;
use proxy_wasm::{self, traits::{Context, HttpContext}};
mod insignia_grpc {
pub mod dev {
pub mod insigniaoss {
pub mod r#type {
include!("../grpc/dev.insigniaoss.type.rs");
}
pub mod service {
pub mod v0 {
include!("../grpc/dev.insigniaoss.service.v0.rs");
}
}
}
}
}
use prost::Message;
use insignia_grpc::dev::insigniaoss;
struct CustomHttpContext {
context_id: u32,
config: Option<InsigniaConfig>,
}
struct CustomRootContext {
config: Option<InsigniaConfig>,
}
#[derive(Clone, Debug, serde::Serialize, serde::Deserialize)]
pub struct InsigniaConfig {
pub grpc_endpoint: String,
}
proxy_wasm::main!{{
proxy_wasm::set_log_level(proxy_wasm::types::LogLevel::Trace);
proxy_wasm::set_root_context(|_| ->
Box<dyn proxy_wasm::traits::RootContext> { Box::new(CustomRootContext{ config: None }) });
}}
impl proxy_wasm::traits::Context for CustomRootContext {}
impl proxy_wasm::traits::Context for CustomHttpContext {
fn on_grpc_call_response(&mut self, _token_id: u32, status_code: u32, response_size: usize) {
log::info!("{{\"context_id\":{},\"verify_user_context_response\":{}}}", self.context_id, status_code);
if status_code % 2 == 0 {
self.get_grpc_call_response_body(0, response_size)
.and_then(|payload| {
if let Ok(user_context) = insigniaoss::service::v0::UserContext::decode(bytes::Bytes::from(payload)) {
return Some(user_context);
}
None
})
.and_then(|user_context| {
log::info!("{{\"context_id\":{},\"is_session_valid\":{}}}", self.context_id, user_context.is_session_valid);
if user_context.is_session_valid {
return user_context.user;
}
None
})
.and_then(|user_context| {
self.set_http_request_header("x-user-id", Some(&user_context.id));
Some(user_context)
});
}
self.resume_http_request();
}
}
impl proxy_wasm::traits::RootContext for CustomRootContext {
fn on_configure(&mut self, _plugin_configuration_size: usize) -> bool {
if let Some(config_bytes) = self.get_plugin_configuration() {
let result = String::from_utf8(config_bytes)
.map_err(|e| e.utf8_error().to_string())
.and_then(|s|
serde_json::from_str::<InsigniaConfig>(&s)
.map_err(|e| e.to_string())
);
return match result {
Ok(config) => {
self.config = Some(config);
true
}
Err(message) => {
log::error!("failed to parse the plugin configuration as InsigniaConfig: {message}");
false
}
};
}
true
}
fn get_type(&self) -> Option<proxy_wasm::types::ContextType> {
Some(proxy_wasm::types::ContextType::HttpContext)
}
fn create_http_context(&self, context_id: u32) -> Option<Box<dyn proxy_wasm::traits::HttpContext>> {
Some(Box::new(CustomHttpContext { context_id, config: self.config.clone() }))
}
}
impl proxy_wasm::traits::HttpContext for CustomHttpContext {
fn on_http_request_headers(&mut self, _: usize, is_end_of_stream: bool) -> proxy_wasm::types::Action {
if is_end_of_stream {
if let Some(config) = &self.config {
let maybe_access_token = self.get_http_request_header("Authorization")
.and_then(|maybe_bearer_token| Some(maybe_bearer_token.replace("Bearer ", "")));
if let Some(maybe_access_token) = maybe_access_token {
let req_headers = HashMap::from_iter(self.get_http_request_headers());
log::warn!("@@@@@@@@@@ {:?}, {:?}", config.grpc_endpoint, insigniaoss::service::v0::ValidateUserContextReq{
req_headers: req_headers.clone(),
access_token: maybe_access_token.clone(),
}.encode_to_vec().as_slice());
// match self.dispatch_grpc_call(
// "grpcbin:9000",
// "grpcbin.GRPCBin",
// "Index",
// vec![],
// None,
// Duration::from_secs(4)
// ) {
// Ok(_) => log::warn!("==== okeerr ====="),
// Err(err) => log::warn!("+++++++++ okeeer +++++++++"),
// }
match self.dispatch_grpc_call(
&config.grpc_endpoint,
"dev.insigniaoss.service.v0.IntegrationService",
"ValidateUserContext",
vec![],
None,
Duration::from_secs(4)
) {
Ok(_) => log::warn!("user context validated"),
Err(err) => log::warn!("failed to validate user context: {:?}", err),
}
return proxy_wasm::types::Action::Pause;
}
}
}
proxy_wasm::types::Action::Continue
}
}
I am using docker-compose to test this filter and the grpc_endpoint in this case point to the service host:port that on the same network as apisix, I verified it using nc -zv [grpc_endpoint] [port] and grpcurl to ensure it can successfully connect from the apisix container and request to it, but when the plugin runs, it panic from the dispatch_grpc_call, tracing it got error in hostcalls.rs:851 I think.
I have tried using another grpc service from moul/grpcbin to test it, the service named grpcbin in the docker compose and test it both grpcbin:9000 and grpcbin without the port since I found some example on how to use the grpc dispatch without the port? but it still give the same error
so far I do not know what the issue is yet and would like to ask for any tips on how to debug and fix this issue.
thanks for your time and work on this project and thanks for your time on reading this as well.
hello @PiotrSikora, thanks for pointing that out, I think I will only use http for now instead of grpc