Python server deleting inactive plugin instances - Error: instance id 0 not found

[valeriobelcastro]

Hi,

I'm testing the python the py-hello plugin but I'm experiencing a weird behaviour. I attached the plugin to a testing service pointing to mockbin.org. The first time I call the service endpoint, the plugin runs correctly:

2021/05/05 09:26:47 [info] 25#0: *8 [python:27] INFO - [17:26:47] instance #0 of py_hello started, context: ngx.timer
2021/05/05 09:26:47 [debug] 25#0: *85 [kong] mp_rpc.lua:332 [py_hello] Hello plugin Called!!!!!

if I call the service again within 60 seconds, the plugin is correctly executed:

2021/05/05 09:27:22 [debug] 25#0: *85 [kong] mp_rpc.lua:332 [py_hello] Hello plugin Called!!!!!

Waiting more than 60 seconds and calling the service again causes a new plugin instance to be created and called:

2021/05/05 09:29:29 [info] 25#0: *8 [python:27] INFO - [17:29:29] instance #1 of py_hello started, context: ngx.timer
2021/05/05 09:29:29 [debug] 26#0: *952 [kong] mp_rpc.lua:332 [py_hello] Hello plugin Called!!!!!

So far so good, everything works as expected.

After the last call to the service, if I wait more than 60 seconds to call it again the plugin is not run and the log shows an error:

2021/05/05 09:31:40 [error] 25#0: *1641 [kong] mp_rpc.lua:354 [py_hello] instance id 0 not found

As a result, the response I receive from Kong does not contain the headers that the py-hello plugin is supposeed to add.

Looking at the python server implementation I noticed that: the PluginServer class, declared in server.py file, starts a thread running the _clear_expired_plugins function to delete plugins instances that are inactive for more than 60 seconds (according to the default expire_ttl parameter which is not set when PluginServer class is instanciated).

My understanding is that those plugin instances get deleted from PluginServer cache (the instances dict declared in the init function) but this information is not sent back to kong which has is how structure to maintain active plugin instances (running_instances present in kong/runloop/plugin_servers/init.lua file). Therefore, Kong tries to call the python plugin passing an instance id that it expects to find but that might not be present in the python PluginServer because of its inactivity, generating an error and preventing plugin execution.

This is what I understood using the error message I received and looking at the code but maybe the problem could be elsewhere (e.g. Kong should tell python server to create a new instance of the plugin each time).

I'm using the docker alpine distibution of Kong 2.4.0 and theses are the lines I added to kong.conf file to configure the plugin:

plugins=bundled,py_hello

pluginserver_names = python
pluginserver_python_socket = /usr/local/kong/python_pluginserver.sock
pluginserver_python_start_cmd = /usr/bin/kong-python-pluginserver --plugins-directory /usr/local/kong/custom-plugins/
pluginserver_python_query_cmd = /usr/bin/kong-python-pluginserver --plugins-directory /usr/local/kong/custom-plugins/ --dump-all-plugins

where /usr/local/kong/custom-plugins/ is a directory I create inside the container and where I place the py-hello.py file

Could you please give it a look?

Thanks!

[fffonion]

@valeriobelcastro I think that's a incorrect behaviour, I will draft a PR to remove it.