proxy-wasm / proxy-wasm-rust-sdk

WebAssembly for Proxies (Rust SDK)
Apache License 2.0
475 stars 94 forks source link

How to execute something just before the instance is terminated? #205

Open aleksousa opened 1 year ago

aleksousa commented 1 year ago

A question about singleton plugins.

I need to execute a process whenever a new instance of my application is created, and another whenever that instance dies. Since each instance has an envoy sidecar, I thought about adding the first logic to on_vm_start, but I couldn't find a way to add an on_delete or something that is executed before the instance is finalized.

I tried implementing it through the RootContext, but I couldn't find anything that worked. Example:

impl RootContext for MyService {
    fn on_vm_start(&mut self, _: usize) -> bool {
        info!("Starting the VM {}", self.id);
        true
    }

    // not available
    fn on_delete(&mut self, _: u32) {
        info!("Terminating the VM {}", self.id);
    }
}

Is it possible to do something like this?

PiotrSikora commented 1 year ago

Did you try on_log or on_done?

aleksousa commented 1 year ago

Good afternoon @PiotrSikora

I had tried with on_log, but it was never executed. I implemented on_done as you suggested and it seems to be working as expected.

However, during testing, I found something strange and I have a question. It seems that 2 plugins are started, or the same one was started 2 times. At the start of the plugin, I create a UUID and assign it to it. So in the log, it shows that 2 UUIDs are starting, but after that, only 1 continues to execute.

Have you ever encountered something like this?

I will leave the code I used for the example and the envoy file.

Plugin Wasm

``` use log::{error, info}; use uuid::Uuid; use proxy_wasm::traits::*; use proxy_wasm::types::*; use std::time::Duration; proxy_wasm::main! {{ proxy_wasm::set_log_level(LogLevel::Trace); proxy_wasm::set_root_context(|_| -> Box { Box::new(Service{ id: Uuid::new_v4(), queue_id: 0, }) }); }} struct Service { id: Uuid, queue_id: u32, } impl Context for Service { fn on_http_call_response(&mut self, _token_id: u32, _num_headers: usize, _body_size: usize, _num_trailers: usize) { if let Some(resp) = self.get_http_call_response_body(0, _body_size) { info!("response {} in VM id {}", String::from_utf8(resp).unwrap(), self.id); } else { error!("invalid response from api"); return; } } fn on_done(&mut self) -> bool { info!("on_done in VM id {}", self.id); true } } impl RootContext for Service { fn on_vm_start(&mut self, _: usize) -> bool { info!("starting VM id {}", self.id); let queue_id = self.register_shared_queue("queue_test"); self.queue_id = queue_id; self.set_tick_period(Duration::new(15, 0)); true } fn on_queue_ready(&mut self, queue_id: u32) { if let Ok(Some(body)) = self.dequeue_shared_queue(queue_id) { if let Ok(r) = std::str::from_utf8(body.as_slice()) { info!("body {} in VM id {}", r, self.id); } else { error!("error reading message body in VM id {}", self.id); } } } fn on_tick(&mut self) { if let Err(err) = self.enqueue_shared_queue(self.queue_id, Some("teste".as_bytes())) { error!("failed to send msg. Error: {:?}", err); } get_config(self); match self.set_shared_data("test", Some("test".as_bytes()), None) { Ok(_) => {} Err(cause) => { error!("unexpected status on set data shared: {:?}", cause) }, } } fn on_log(&mut self) { info!("on_log exec in VM id {}", self.id); } } pub fn get_config(ctx: &dyn Context) { let headers = vec![ (":method", "GET"), (":path", "/config"), (":scheme", "http"), (":authority", "go-config"), ]; match ctx.dispatch_http_call("my-api", headers, None, vec![], Duration::new(10, 0)) { Ok(_) => {}, Err(status) => { error!("error dispatching call to service: {:?}", status) } } } ```

Envoy File

``` admin: address: socket_address: address: 0.0.0.0 port_value: 9901 bootstrap_extensions: - name: envoy.bootstrap.wasm typed_config: "@type": type.googleapis.com/envoy.extensions.wasm.v3.WasmService singleton: true config: configuration: "@type": type.googleapis.com/google.protobuf.StringValue value: {} vm_config: vm_id: "my-vm" runtime: "envoy.wasm.runtime.v8" code: local: filename: "/etc/envoy/service.wasm" static_resources: listeners: - name: listener_0 address: socket_address: address: 0.0.0.0 port_value: 10000 filter_chains: - filters: - name: envoy.filters.network.http_connection_manager typed_config: "@type": type.googleapis.com/envoy.extensions.filters.network.http_connection_manager.v3.HttpConnectionManager access_log: - name: envoy.access_loggers.stdout typed_config: "@type": type.googleapis.com/envoy.extensions.access_loggers.stream.v3.StdoutAccessLog stat_prefix: ingress_http route_config: name: local_route virtual_hosts: - name: local_service domains: ["*"] routes: - match: prefix: "/rate" route: cluster: app priority: "HIGH" http_filters: - name: envoy.filters.http.router typed_config: "@type": type.googleapis.com/envoy.extensions.filters.http.router.v3.Router clusters: - name: app connect_timeout: 0.25s type: STRICT_DNS lb_policy: ROUND_ROBIN load_assignment: cluster_name: app endpoints: - lb_endpoints: - endpoint: address: socket_address: address: go-app port_value: 8080 circuit_breakers: thresholds: max_pending_requests: 65536 max_requests: 65536 max_connections: 65536 ```

Logs

``` poc-wasm-envoy-1 | [2023-08-22 17:43:15.146][1][info][admin] [source/server/admin/admin.cc:66] admin address: 0.0.0.0:9901 poc-wasm-envoy-1 | [2023-08-22 17:43:15.146][1][info][config] [source/server/configuration_impl.cc:131] loading tracing configuration poc-wasm-envoy-1 | [2023-08-22 17:43:15.146][1][info][config] [source/server/configuration_impl.cc:91] loading 0 static secret(s) poc-wasm-envoy-1 | [2023-08-22 17:43:15.146][1][info][config] [source/server/configuration_impl.cc:97] loading 1 cluster(s) poc-wasm-envoy-1 | [2023-08-22 17:43:15.148][1][info][config] [source/server/configuration_impl.cc:101] loading 1 listener(s) poc-wasm-envoy-1 | [2023-08-22 17:43:15.151][1][info][config] [source/server/configuration_impl.cc:113] loading stats configuration poc-wasm-envoy-1 | [2023-08-22 17:43:15.237][1][info][wasm] [source/extensions/common/wasm/context.cc:1148] wasm log my-vm: starting VM id c39e601f-be43-411b-a2f7-1fc3543bd1e2 poc-wasm-envoy-1 | [2023-08-22 17:43:15.240][1][info][wasm] [source/extensions/common/wasm/context.cc:1148] wasm log my-vm: starting VM id 36a24863-6246-4edf-a471-37e72e95a3ec poc-wasm-envoy-1 | [2023-08-22 17:43:15.241][1][info][main] [source/server/server.cc:923] starting main dispatch loop poc-wasm-envoy-1 | [2023-08-22 17:43:15.241][1][info][runtime] [source/common/runtime/runtime_impl.cc:463] RTDS has finished initialization poc-wasm-envoy-1 | [2023-08-22 17:43:15.241][1][info][upstream] [source/common/upstream/cluster_manager_impl.cc:225] cm init: all clusters initialized poc-wasm-envoy-1 | [2023-08-22 17:43:15.241][1][info][main] [source/server/server.cc:904] all clusters initialized. initializing init manager poc-wasm-envoy-1 | [2023-08-22 17:43:15.241][1][info][config] [source/extensions/listener_managers/listener_manager/listener_manager_impl.cc:858] all dependencies initialized. starting workers poc-wasm-envoy-1 | [2023-08-22 17:43:15.241][1][warning][main] [source/server/server.cc:802] there is no configured limit to the number of allowed active connections. Set a limit via the runtime key overload.global_downstream_max_connections poc-wasm-envoy-1 | [2023-08-22 17:43:30.236][1][error][wasm] [source/extensions/common/wasm/context.cc:1154] wasm log my-vm: error dispatching call to service: BadArgument poc-wasm-envoy-1 | [2023-08-22 17:43:30.240][1][info][wasm] [source/extensions/common/wasm/context.cc:1148] wasm log my-vm: body teste in VM id 36a24863-6246-4edf-a471-37e72e95a3ec poc-wasm-envoy-1 | [2023-08-22 17:43:45.243][1][error][wasm] [source/extensions/common/wasm/context.cc:1154] wasm log my-vm: error dispatching call to service: BadArgument poc-wasm-envoy-1 | [2023-08-22 17:43:45.243][1][info][wasm] [source/extensions/common/wasm/context.cc:1148] wasm log my-vm: body teste in VM id 36a24863-6246-4edf-a471-37e72e95a3ec poc-wasm-envoy-1 | [2023-08-22 17:44:00.238][1][error][wasm] [source/extensions/common/wasm/context.cc:1154] wasm log my-vm: error dispatching call to service: BadArgument poc-wasm-envoy-1 | [2023-08-22 17:44:00.238][1][info][wasm] [source/extensions/common/wasm/context.cc:1148] wasm log my-vm: body teste in VM id 36a24863-6246-4edf-a471-37e72e95a3ec poc-wasm-envoy-1 | [2023-08-22 17:44:15.237][1][error][wasm] [source/extensions/common/wasm/context.cc:1154] wasm log my-vm: error dispatching call to service: BadArgument poc-wasm-envoy-1 | [2023-08-22 17:44:15.237][1][info][wasm] [source/extensions/common/wasm/context.cc:1148] wasm log my-vm: body teste in VM id 36a24863-6246-4edf-a471-37e72e95a3ec poc-wasm-envoy-1 | [2023-08-22 17:44:30.234][1][error][wasm] [source/extensions/common/wasm/context.cc:1154] wasm log my-vm: error dispatching call to service: BadArgument poc-wasm-envoy-1 | [2023-08-22 17:44:30.235][1][info][wasm] [source/extensions/common/wasm/context.cc:1148] wasm log my-vm: body teste in VM id 36a24863-6246-4edf-a471-37e72e95a3ec poc-wasm-envoy-1 | [2023-08-22 17:44:38.704][1][warning][main] [source/server/server.cc:862] caught ENVOY_SIGTERM poc-wasm-envoy-1 | [2023-08-22 17:44:38.704][1][info][main] [source/server/server.cc:993] shutting down server instance poc-wasm-envoy-1 | [2023-08-22 17:44:38.704][1][info][main] [source/server/server.cc:1047] Notifying 0 callback(s) with completion. poc-wasm-envoy-1 | [2023-08-22 17:44:38.704][1][info][main] [source/server/server.cc:928] main dispatch loop exited poc-wasm-envoy-1 | [2023-08-22 17:44:38.706][1][info][main] [source/server/server.cc:980] exiting poc-wasm-envoy-1 | [2023-08-22 17:44:38.708][1][info][wasm] [source/extensions/common/wasm/context.cc:1148] wasm log my-vm: on_done in VM id 36a24863-6246-4edf-a471-37e72e95a3ec poc-wasm-envoy-1 exited with code 0 ```

PiotrSikora commented 1 year ago

on_vm_start is called by the "canary" instance that's instantiating the plugin to check if the configuration is valid, and it's discarded afterwards.

aleksousa commented 1 year ago

Is there any way I can differentiate between these two flows in on_vm_start?

balbifm commented 1 year ago

on_vm_start is called by the "canary" instance that's instantiating the plugin to check if the configuration is valid, and it's discarded afterwards.

Is the on_configure called as well in that process?

PiotrSikora commented 1 year ago

Is there any way I can differentiate between these two flows in on_vm_start?

Unfortunately, currently it's not (I agree that's not great).

Note that both canary and "regular" plugin are started in the same WasmVM, so you could store some state in global variables within the plugin, but keep in mind that the same WasmVM is also reused across multiple instances of the same plugin with different plugin configurations, so you'd need to account for that.

PiotrSikora commented 1 year ago

Is the on_configure called as well in that process?

Yes.