How to execute something just before the instance is terminated?

[aleksousa]

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]

Did you try on_log or on_done?

[aleksousa]

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<dyn RootContext> {
        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]

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]

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

[balbifm]

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]

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]

Is the on_configure called as well in that process?

Yes.