Error with middleware in one gateway while other pods are working fine

[utkarsh079]

Branch/Environment/Version

• Branch/Version: Master
• Environment: EKS

Describe the bug
We are running 3 gateway pods using the same volumes. The middleware path is '/mnt/tyk-gateway/middlewares/bundles'. Yesterday after deploying a new bundle of middleware, traffic from 2 pods was perfectly okay while all the incoming traffic to one particular pod started failing due to 'error="PyObjectCallObject failed" mw=CoProcessMiddleware'. Its a simple python plugin which is implementing host ip based rate limiting. Since the its an 'auth_check' hook, all the traffic from this pod started failing with 403.
There were no changes to plugin at all and the same plugin was working okay with other pods.

Reproduction steps
Steps to reproduce the behavior:

1. Deploy multiple replica pods of gateway
2. Deploy a new bundle of python plugin

Actual behavior
Traffic from one pod kept on failing and resturning 403 to clients

Expected behavior
Traffic should be passed properly from all the pods

Logs (debug mode or log file):
Some relevant logs I can gather:

 
Jan 30, 2024 15:01:01.163
time="Jan 30 15:01:01" level=info msg="----> Fetching Bundle: Bundle-624671e908b6684f4a87609b78514280aca6b765.zip" prefix=main
gateway-tyk-gateway-tyk-headless-54d7f8f456-lmpkd
 
Jan 30, 2024 15:01:01.163
time="Jan 30 15:01:01" level=info msg="Attempting to download plugin bundle: https://<s3>/bundles/Bundle-624671e908b6684f4a87609b78514280aca6b765.zip"
gateway-tyk-gateway-tyk-headless-54d7f8f456-lmpkd
 
Jan 30, 2024 15:01:01.242
time="Jan 30 15:01:01" level=debug msg="----> Saving Bundle: Bundle-624671e908b6684f4a87609b78514280aca6b765.zip" prefix=main
gateway-tyk-gateway-tyk-headless-54d7f8f456-hwb6s
 
Jan 30, 2024 15:01:01.242
time="Jan 30 15:01:01" level=info msg="----> Loading bundle: Bundle-624671e908b6684f4a87609b78514280aca6b765.zip" prefix=main
gateway-tyk-gateway-tyk-headless-54d7f8f456-hwb6s
 
Jan 30, 2024 15:01:01.243
time="Jan 30 15:01:01" level=info msg="----> Couldn't unmarshal the manifest file for bundle: Bundle-624671e908b6684f4a87609b78514280aca6b765.zip" prefix=main
gateway-tyk-gateway-tyk-headless-54d7f8f456-hwb6s
 
Jan 30, 2024 15:01:01.249
time="Jan 30 15:01:01" level=debug msg="----> Saving Bundle: Bundle-624671e908b6684f4a87609b78514280aca6b765.zip" prefix=main
gateway-tyk-gateway-tyk-headless-54d7f8f456-lmpkd
 
Jan 30, 2024 15:01:01.249
time="Jan 30 15:01:01" level=info msg="----> Loading bundle: Bundle-624671e908b6684f4a87609b78514280aca6b765.zip" prefix=main
gateway-tyk-gateway-tyk-headless-54d7f8f456-lmpkd
 
Jan 30, 2024 15:01:01.252
time="Jan 30 15:01:01" level=info msg="----> Verifying bundle: Bundle-624671e908b6684f4a87609b78514280aca6b765.zip" prefix=main
gateway-tyk-gateway-tyk-headless-54d7f8f456-lmpkd
 
Jan 30, 2024 15:01:01.258
time="Jan 30 15:01:01" level=info msg="----> Bundle is valid, adding to spec: Bundle-624671e908b6684f4a87609b78514280aca6b765.zip" prefix=main
gateway-tyk-gateway-tyk-headless-54d7f8f456-lmpkd
 
Jan 30, 2024 15:01:01.281
time="Jan 30 15:01:01" level=info msg="----> Fetching Bundle: Bundle-624671e908b6684f4a87609b78514280aca6b765.zip" prefix=main
gateway-tyk-gateway-tyk-headless-54d7f8f456-hwb6s
 
Jan 30, 2024 15:01:01.281
time="Jan 30 15:01:01" level=info msg="Attempting to download plugin bundle: https://<>/bundles/Bundle-624671e908b6684f4a87609b78514280aca6b765.zip"
gateway-tyk-gateway-tyk-headless-54d7f8f456-hwb6s
 
Jan 30, 2024 15:01:01.357
time="Jan 30 15:01:01" level=debug msg="----> Saving Bundle: Bundle-624671e908b6684f4a87609b78514280aca6b765.zip" prefix=main
gateway-tyk-gateway-tyk-headless-54d7f8f456-hwb6s
 
Jan 30, 2024 15:01:01.357
time="Jan 30 15:01:01" level=info msg="----> Loading bundle: Bundle-624671e908b6684f4a87609b78514280aca6b765.zip" prefix=main
gateway-tyk-gateway-tyk-headless-54d7f8f456-hwb6s
 
Jan 30, 2024 15:01:01.358
time="Jan 30 15:01:01" level=info msg="----> Verifying bundle: Bundle-624671e908b6684f4a87609b78514280aca6b765.zip" prefix=main
gateway-tyk-gateway-tyk-headless-54d7f8f456-hwb6s
 
Jan 30, 2024 15:01:01.361
time="Jan 30 15:01:01" level=info msg="----> Bundle is valid, adding to spec: Bundle-624671e908b6684f4a87609b78514280aca6b765.zip" prefix=main
gateway-tyk-gateway-tyk-headless-54d7f8f456-hwb6s
 
Jan 30, 2024 15:01:01.435
time="Jan 30 15:01:01" level=info msg="Loading existing bundle: Bundle-624671e908b6684f4a87609b78514280aca6b765.zip" prefix=main
gateway-tyk-gateway-tyk-headless-54d7f8f456-hwb6s
 
Jan 30, 2024 15:01:01.435
time="Jan 30 15:01:01" level=info msg="----> Loading bundle: Bundle-624671e908b6684f4a87609b78514280aca6b765.zip" prefix=main
gateway-tyk-gateway-tyk-headless-54d7f8f456-hwb6s
 
Jan 30, 2024 15:01:01.437
time="Jan 30 15:01:01" level=info msg="----> Using bundle: Bundle-624671e908b6684f4a87609b78514280aca6b765.zip" prefix=main

More logs:

time="Jan 30 15:01:01" level=error msg="Middleware initialization error: [Errno 2] No such file or directory: '/mnt/tyk-gateway/middleware/bundles/3d2f488417a4b21e97b2accc98522548/middleware.py'" prefix=python

Actual error logs while failing

 
Jan 30, 2024 15:01:04.298
time="Jan 30 15:01:04" level=error msg="Dispatch error" api_id=YWR0L2Nhcmdvcy1hcGktbWFzdGVyLWFwaS12b3J0ZXhhLWNvbQ api_name=<api-name>error="PyObjectCallObject failed" mw=CoProcessMiddleware org_id= origin=10.3.3.198 path=/v5/time-series
gateway-tyk-gateway-tyk-headless-54d7f8f456-lmpkd
 
Jan 30, 2024 15:01:04.353
time="Jan 30 15:01:04" level=error msg="Dispatch error" api_id=YWR0L2Nhcmdvcy1hcGktbWFzdGVyLWFwaS12b3J0ZXhhLWNvbQ api_name=<api-name>error="PyObjectCallObject failed" mw=CoProcessMiddleware org_id= origin=10.3.1.129 path=/v5/breakdown/origin
gateway-tyk-gateway-tyk-headless-54d7f8f456-lmpkd

Additional context
I suspect the reason being the same bundle being downloaded multiple times by each gateway pod could have created some corruption. But I am not really sure. I am certain that there are no issues with bundle.

[utkarsh079]

Few more things I found while trying to figure out an RCA:
The bundle was downloaded 4 times (2 times by each pod in a seconds time)

Event after that, for about 500 ms, traffic was processed properly but for some reason a reset was initiated and the issue started coming after that.