Python plugins other than Auth

Hi,

I’ve been playing a little with the middleware and I have a few things that I can’t get to work or don’t understand quite well enough.
I have an on-premise installation.

So here we go, I started by creating a JS middleware using the folders and it worked pretty well. I managed to create a redirection based on a set of rules (conditons). But I feel like the JS middleware is meant only for light things and in my next project it might not be enough (example, Auth linked to LDAP).

So I went on to try Python middleware. I created a project with a manifest.json and a middleware.py files. Then used the tyk-cli to create a bundle, set it in the API description via the Dashboard UI and I got the Auth plugin from the demo to work. Cool !

Now I’m trying to use another Hook than the Auth one. Post or Pre. I updated my python file like this :

from tyk.decorators import *
from gateway import TykGateway as tyk

@Hook
def MyAuthMiddleware(request, session, metadata, spec):
log(“hahahahaha”)
auth_header = request.get_header(‘Authorization’)
if auth_header == ‘47a0c79c427728b3df4af62b9228c8ae’:
session.rate = 1000.0
session.per = 1.0
metadata[“token”] = “47a0c79c427728b3df4af62b9228c8ae”
return request, session, metadata

@Hook
def MyPreMiddleware(request, session, spec):
print(“my_middleware: MyPreMiddleware”)
return request, session

@Hook
def MyPostMiddleware(request, session, spec):
print(“my_middleware: MyPostMiddleware”)
return request, session

and my manifest like this :

{
“file_list”: [
“middleware.py”
],
“custom_middleware”: {
“pre”:[{
“name”: “MyPreMiddleware”,
“require_session”: false
}],
“post”:[{
“name”: “MyPostMiddleware”,
“require_session”: false
}],
“driver”: “python”,
“auth_check”: {
“name”: “MyAuthMiddleware”
}
}
}

I updated my bundle in the API config, restarted my tyk-gateway-python service and my Auth plugin still works.
Except I get these errors :
time=“Oct 20 14:57:05” level=error msg=“Can’t dispatch ‘MyPreMiddleware’, hook is not defined.”
time=“Oct 20 14:57:05” level=warning msg=“Incorrect key expiry setting detected, correcting”
time=“Oct 20 14:57:05” level=error msg=“Can’t dispatch ‘MyPostMiddleware’, hook is not defined.”

I do not understand why…
Also, I do not see my log(“hahahahaha”) in the service logs. Am I missing something ?

Another thing, since I added my bundle I get an error about my JS middleware that I didn’t get before. Does that mean that you cannot have both at the same time ?
Error is : time=“Oct 20 15:10:50” level=error msg=“Can’t dispatch ‘action’, hook is not defined.”

Quick kinda related question : Is it possible to have a bundle for JS middleware in the same way ? Also, I couldn’t get the HTTP method with the JS code, is there a way to retrieve it ?

Basically my project will have 2 plugins need. An LDAP connector and some rules for redirecting some endpoint to another if some conditions are met, those conditions will be based on data from a third endpoint.

Thanks a lot for any input on any of that ! :slight_smile:

Cheers,
Robert

Hi Robert,

what is your Gateway version ?
We have recently released a patch that should address this issue.

Thanks,
Kos @ Tyk Support Team

Hi Kos,

Thanks for your quick feedback !

I updated the version :
time=“Oct 20 15:47:21” level=info msg=“Gateway started (v2.3.10)”

But I still get the same errors :
time=“Oct 20 15:50:36” level=error msg=“Can’t dispatch ‘MyPreMiddleware’, hook is not defined.”
time=“Oct 20 15:50:36” level=warning msg=“Incorrect key expiry setting detected, correcting”
time=“Oct 20 15:50:36” level=error msg=“Can’t dispatch ‘MyPostMiddleware’, hook is not defined.”
time=“Oct 20 15:50:36” level=error msg=“Can’t dispatch ‘action’, hook is not defined.”

Here is the content from my bundle loaded in /opt/tyk-gateway/middleware/bundles/7c05a8064aa045285cfc4eedb5ad0e6a-bundle14.zip

manifest.json

{
“file_list”: [“middleware.py”],
“custom_middleware”: {
“pre”: [{
“name”: “MyPreMiddleware”,
“path”: “”,
“require_session”: false
}],
“post”: [{
“name”: “MyPostMiddleware”,
“path”: “”,
“require_session”: false
}],
“post_key_auth”: null,
“auth_check”: {
“name”: “MyAuthMiddleware”,
“path”: “”,
“require_session”: false
},
“response”: null,
“driver”: “python”,
“id_extractor”: {
“extract_from”: “”,
“extract_with”: “”,
“extractor_config”: null
}
},
“checksum”: “b09899d8a753ea987f26c5ebb05d837b”,
“signature”: “”
}

middleware.py

from tyk.decorators import *
from gateway import TykGateway as tyk

@Hook
def MyAuthMiddleware(request, session, metadata, spec):
log(“hahahahaha”)
auth_header = request.get_header(‘Authorization’)
if auth_header == ‘47a0c79c427728b3df4af62b9228c8ae’:
session.rate = 1000.0
session.per = 1.0
metadata[“token”] = “47a0c79c427728b3df4af62b9228c8ae”
return request, session, metadata

@Hook
def MyPreMiddleware(request, session, spec):
print(“my_middleware: MyPreMiddleware”)
return request, session

@Hook
def MyPostMiddleware(request, session, spec):
print(“my_middleware: MyPostMiddleware”)
return request, session

Hi @Rouzz, can you share the full gateway log?

Hi @matiasb,

Here is the full log of a restart + subsequent call to my API for which I activated the bundle.

– Logs begin at Fri 2017-10-20 18:00:01 CEST, end at Fri 2017-10-20 18:16:02 CEST. –
Oct 20 18:14:05 BLUEMINTRVIONNY systemd[1]: Stopping Tyk API Gateway (Python Support)…
Oct 20 18:14:05 BLUEMINTRVIONNY tyk-python[27261]: 2017/10/20 18:14:05 terminated
Oct 20 18:14:05 BLUEMINTRVIONNY tyk-python[27261]: time=“Oct 20 18:14:05” level=info msg=“Stop signal received.”
Oct 20 18:14:05 BLUEMINTRVIONNY tyk-python[27261]: time=“Oct 20 18:14:05” level=info msg=“Stopping heartbeat…”
Oct 20 18:14:07 BLUEMINTRVIONNY tyk-python[27261]: time=“Oct 20 18:14:07” level=info msg=“Stopped Heartbeat”
Oct 20 18:14:07 BLUEMINTRVIONNY tyk-python[27261]: time=“Oct 20 18:14:07” level=info msg=“De-registering: aa7b167b-e468-47e0-5ab2-dd61aa76d1be”
Oct 20 18:14:07 BLUEMINTRVIONNY tyk-python[27261]: time=“Oct 20 18:14:07” level=info msg=De-registered.
Oct 20 18:14:07 BLUEMINTRVIONNY tyk-python[27261]: time=“Oct 20 18:14:07” level=info msg=Terminating.
Oct 20 18:14:10 BLUEMINTRVIONNY systemd[1]: Stopped Tyk API Gateway (Python Support).
Oct 20 18:14:10 BLUEMINTRVIONNY systemd[1]: Started Tyk API Gateway (Python Support).
Oct 20 18:14:10 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:10” level=info msg=“Connection dropped, connecting…”
Oct 20 18:14:10 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:10” level=info msg=“Setting PYTHONPATH to ‘coprocess/python:middleware/python:event_handlers:coprocess/python/proto:/opt/tyk-gateway/middleware/bundles/7c05a8064aa045285cfc4eedb5ad0e6a-bundle10.zip:/opt/tyk-gateway/middleware/bundles/7c05a8064aa045285cfc4eedb5ad0e6a-bundle11.zip:/opt/tyk-gateway/middleware/bundles/7c05a8064aa045285cfc4eedb5ad0e6a-bundle12.zip:/opt/tyk-gateway/middleware/bundles/7c05a8064aa045285cfc4eedb5ad0e6a-bundle13.zip:/opt/tyk-gateway/middleware/bundles/7c05a8064aa045285cfc4eedb5ad0e6a-bundle14.zip:/opt/tyk-gateway/middleware/bundles/7c05a8064aa045285cfc4eedb5ad0e6a-bundle9.zip’”
Oct 20 18:14:10 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:10” level=info msg=“Initializing interpreter, Py_Initialize()”
Oct 20 18:14:10 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:10” level=info msg=“Initializing dispatcher”
Oct 20 18:14:10 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:10” level=info msg=“Setting up analytics normaliser”
Oct 20 18:14:10 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:10” level=info msg=“PIDFile location set to: ./tyk-gateway.pid”
Oct 20 18:14:10 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:10” level=error msg=“Instrumentation is enabled, but no connectionstring set for statsd”
Oct 20 18:14:10 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:10” level=info msg=“Initialising Tyk REST API Endpoints”
Oct 20 18:14:10 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:10” level=info msg="–> Standard listener (http)"
Oct 20 18:14:10 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:10” level=info msg=“Setting up Server”
Oct 20 18:14:10 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:10” level=info msg=“Waiting for zeroconf signal…”
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=warning msg=“Insecure configuration detected (allowing)!”
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Hostname set with dashboard zeroconf signal”
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Registering node.”
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Node registered” id=aa7b167b-e468-47e0-5ab2-dd61aa76d1be
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Initialising distributed rate limiter”
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Starting gateway rate imiter notifications…”
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Detected 3 APIs”
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Loading API configurations.”
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Tracking hostname” api_name=“Local Directus” domain="(no host)"
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Tracking hostname” api_name=“Local API” domain="(no host)"
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Tracking hostname” api_name=“First test with http bin” domain="(no host)"
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Loading API” api_name=“Local Directus”
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Loading API” api_name=“Local API”
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Checking security policy: Token” api_name=“Local Directus”
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Loading API” api_name=“First test with http bin”
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Loaded: Local Directus” api_id=eea7a012af7a4b29745b510b36d12b34 org_id=59e5c9f3763e950fc542e51a server_name=-- user_id=-- user_ip=–
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Checking security policy: Token” api_name=“Local API”
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Loaded: Local API” api_id=4937f0730250423e498b0c57654788a0 org_id=59e5c9f3763e950fc542e51a server_name=-- user_id=-- user_ip=–
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Loading existing bundle: bundle14.zip”
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg="----> Loading bundle: bundle14.zip"
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg="----> Using bundle: bundle14.zip"
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Loading module: ‘middleware’”
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Checking security policy: CoProcess Plugin” api_name=“First test with http bin”
Oct 20 18:14:12 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:12” level=info msg=“Loaded: First test with http bin” api_id=7c05a8064aa045285cfc4eedb5ad0e6a org_id=59e5c9f3763e950fc542e51a server_name=-- user_id=-- user_ip=–
Oct 20 18:14:13 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:13” level=info msg=“Processed and listening on: /local-directus/{rest:.}"
Oct 20 18:14:13 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:13” level=info msg="Processed and listening on: /local-api/{rest:.
}”
Oct 20 18:14:14 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:13” level=info msg=“Processed and listening on: /httpbin/{rest:.*}”
Oct 20 18:14:14 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:13” level=info msg=“Loading uptime tests…”
Oct 20 18:14:14 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:13” level=info msg=“Initialised API Definitions”
Oct 20 18:14:14 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:13” level=info msg=“Loading policies”
Oct 20 18:14:14 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:13” level=info msg=“Using Policies from Dashboard Service”
Oct 20 18:14:14 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:13” level=info msg=“Mutex lock acquired… calling”
Oct 20 18:14:14 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:13” level=info msg=“Calling dashboard service for policy list”
Oct 20 18:14:14 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:14” level=info msg=“Processing policy list”
Oct 20 18:14:14 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:14” level=info msg="–> Processing policy ID: 59e5cc2b763e950fc542e51e"
Oct 20 18:14:14 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:14” level=info msg="–> Processing policy ID: 59ea033b763e956fbbaf5c35"
Oct 20 18:14:14 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:14” level=info msg=“Gateway started (v2.3.10)”
Oct 20 18:14:14 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:14” level=info msg="–> Listening on address: (open interface)"
Oct 20 18:14:14 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:14” level=info msg="–> Listening on port: 8080"
Oct 20 18:14:14 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:14” level=info msg="–> PID: 24759"
Oct 20 18:14:15 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:15” level=info msg=“Using /opt/tyk-gateway/tyk.conf for configuration”
Oct 20 18:14:20 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:20” level=info msg=“Starting Poller”
Oct 20 18:14:41 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:41” level=error msg=“Can’t dispatch ‘MyPreMiddleware’, hook is not defined.”
Oct 20 18:14:41 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:41” level=warning msg=“Incorrect key expiry setting detected, correcting”
Oct 20 18:14:41 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:41” level=error msg=“Can’t dispatch ‘MyPostMiddleware’, hook is not defined.”
Oct 20 18:14:41 BLUEMINTRVIONNY tyk-python[24759]: time=“Oct 20 18:14:41” level=error msg=“Can’t dispatch ‘action’, hook is not defined.”

Thanks

Hello again,

I kept trying and I removed the former imported bundles. Apparently there was some kind of cache on the code, I no longer get the “can’t dispatch error” for python code anymore.

So then I got a “‘log’ is not defined” and replaced its use with “print”.
Now it seems to be working but I never see anything printed in the service logs.

So my questions are :

  • How can I see the logs where data are printed or how can I get the “log” function to work ?
  • What was this cache thing about ? Is it about the “Caching middleware” advanced option ? The logs always confirmed that the latest bundle was used so I don’t know…
  • In the Auth demo the python function have 4 parameters, in the pre/post middleware example there is only 3. Is it normal ? I tried adding a 4th one to the post middleware and it doesn’t seem to break anything but I cannot check what is inside each parameter without knowing how to log/print stuff
  • I still get the error for my JS middleware, can you confirm that both middleware cannot be used on a single API ?

EDIT : One more thing, I just deactivated my Auth plugin (since I want to test other Hooks) by changing API conf but the hardcoded token from the demo is still accepted by the system, even for other registered APIs that had nothing to do with the Python bundle. It became something like a master key that let me query anything. Is this a known issue ?

Thanks a lot !
Robert

If you used the ID Extractor with a long TTL, then the key will still exist, and if you provided that key with an empty ACL, it will be a master key and allow access to everything.

Hey Martin,

Thanks for the feedback.
I’m not sure I did all that since I just copy/pasted the demo code but it was just an after thought since this is a test install.

Do you have any answers for my other questions ? Mostly the ones about how to use “log” with python and this cache issue that would be problematic on a server where I cannot delete the old bundle folders. That would be awesome :slight_smile:

Thanks again,
Robert

Logs are dependent on your OS and distro, in ubuntu they are under /var/log/upstart

Not sure what this is, we have specialised caching middleware in tyk, it has nothing to with plugins.

Auth plugins can cache plugin responses to reduce the number of times the code needs to be executed per user, see the docs for the ID Extractor here.

If te demo you were using made use of the ID Extractor, then those credentials would have ben cached in redis indefinetely (you can set a TTL in the auth plugin).

Yes they are: (request, session, metadata, spec), the pre and post auth middleware will not need all of those and so are not passed them, Auth is a special case, the regular MW will have def MyPreMiddleware(request, session, spec):, there is no meta-data.

It’s either python or JS, I don;t think it can be both in the same runtime.