search

TykTechnologies / tyk

Tyk Open Source API Gateway written in Go, supporting REST, GraphQL, TCP and gRPC protocols
Other
9.65k stars 1.09k forks source link

Error in gGolang auth plugin : "Session state is missing or unset! Please make sure that auth headers are properly applied" #4553

Closed Lajule closed 1 year ago

Lajule commented 1 year ago

Describe the bug I get the following error in my golang plugin : time="Dec 18 19:04:21" level=debug msg=Finished api_id=1 api_name="Test API" code=400 error="Session state is missing or unset! Please make sure that auth headers are properly applied" mw=KeyExpired ns=142918 org_id=1 origin=172.18.0.1 path="/test-api/status/200"

Reproduction steps I start the gateway with (form getting started) :

docker network create tyk docker run -d --rm --name redis --network tyk -p 6379:6379 redis:4.0-alpine
docker run -d --rm --name tyk_gateway --network tyk -p 8080:8080 \
-v $$PWD/tyk.standalone.conf:/opt/tyk-gateway/tyk.conf \
-v $$PWD/AuthCheck.so:/opt/tyk-gateway/AuthCheck.so \
-v $$PWD/apps:/opt/tyk-gateway/apps \
docker.tyk.io/tyk-gateway/tyk-gateway:latest

with following Tyk configuration: {
"log_level": "debug" ,
"listen_port": 8080,
"secret": "352d20ee67be67f6340b4c0605b044b7",
"template_path": "/opt/tyk-gateway/templates",
"tyk_js_path": "/opt/tyk-gateway/js/tyk.js",
"middleware_path": "/opt/tyk-gateway/middleware",
"use_db_app_configs": false,
"app_path": "/opt/tyk-gateway/apps/",
"storage": {
"type": "redis",
"host": "redis",
"port": 6379,
"username": "",
"password": "",
"database": 0,
"optimisation_max_idle": 2000,
"optimisation_max_active": 4000
},
"enable_analytics": false,
"analytics_config": {
"type": "",
"ignored_ips": []
},
"health_check": {
"enable_health_checks": false,
"health_check_value_timeouts": 60
},
"optimisations_use_async_session_write": false,
"enable_non_transactional_rate_limiter": true,
"enable_sentinel_rate_limiter": false,
"enable_redis_rolling_limiter": false,
"allow_master_keys": false,
"policies": {
"policy_source": "file",
"policy_record_name": "/opt/tyk-gateway/policies/policies.json"
},
"hash_keys": true,
"close_connections": false,
"http_server_options": {
"enable_websockets": true
},
"allow_insecure_configs": true,
"coprocess_options": {
"enable_coprocess": true,
"coprocess_grpc_server": ""
},
"enable_bundle_downloader": true,
"bundle_base_url": "",
"global_session_lifetime": 100,
"force_global_session_lifetime": false,
"max_idle_connections_per_host": 500,
"enable_jsvm": true
}

I have the following api : {
"name": "Test API",
"slug": "test-api",
"api_id": "1",
"org_id": "1",
"auth_configs": {
"authToken": {
"auth_header_name": "Authorization"
}
},
"use_keyless": false,
"use_go_plugin_auth": true,
"definition": {
"location": "header",
"key": "x-api-version"
},
"version_data": {
"not_versioned": true,
"versions": {
"Default": {
"name": "Default",
"use_extended_paths": true
}
}
},
"proxy": {
"listen_path": "/test-api/",
"target_url": "http://echo.tyk-demo.com:8080/",
"strip_listen_path": true
},
"custom_middleware": {
"auth_check": {
"name": "AuthCheck",
"path": "/opt/tyk-gateway/AuthCheck.so"
},
"driver": "goplugin"
},
"active": true
}

I build the following plugin : package main

import (
"encoding/json"
"io/ioutil"
"net/http"
"net/url"
"strings" 

"github.com/TykTechnologies/tyk/ctx"  
"github.com/TykTechnologies/tyk/log"  
"github.com/TykTechnologies/tyk/user"

)

const (
prefix = "Bearer " 

endpoint = "https://auth.server.com/oauth2/introspect"  

clientID = "test"  

clientSecret = "test"

)

var (
logger = log.Get()
)

func introspect(token string) (int, []byte, error) {
params := url.Values{}
params.Add("token", token) 

reader := strings.NewReader(params.Encode())  
req, err := http.NewRequest(http.MethodPost, endpoint, reader)  
if err != nil {  
    logger.Errorf("failed to create request: %v", err)  
    return 0, nil, err  
}  

req.Header.Add("Content-Type", "application/x-www-form-urlencoded")  

client := &http.Client{  
    Transport: &http.Transport{  
        DisableKeepAlives: true,  
    },  
}  

resp, err := client.Do(req)  
if err != nil {  
    logger.Errorf("failed to send request: %v", err)  
    return 0, nil, err  
}

body, err := ioutil.ReadAll(resp.Body)  
resp.Body.Close()  
if err != nil {  
    logger.Errorf("failed to read body: %v", err)  
    return 0, nil, err  
}  

return resp.StatusCode, body, nil

}

// AuthCheck introspects auth token
func AuthCheck(rw http.ResponseWriter, r *http.Request) {
authorization := r.Header.Get("Authorization") 

if !strings.HasPrefix(authorization, prefix) {  
    logger.Warn("no bearer token")  
    rw.WriteHeader(http.StatusUnauthorized)  
    return  
}  

token := strings.TrimPrefix(authorization, prefix)  

status, body, err := introspect(token)  
if err != nil {  
    logger.Errorf("failed to introspect token: %v", err)  
    rw.WriteHeader(http.StatusInternalServerError)  
    return  
}  

if status != http.StatusOK {  
    logger.Errorf("status code is not ok: %d", status)  
    rw.Header().Set("Content-Type", "application/json")  
    rw.WriteHeader(http.StatusUnauthorized)  
    rw.Write(body)  
    return  
}  

session := &user.SessionState{  
    OrgID: "1",  
    Alias: "oauth-session",  
}  

logger.Debugf("unmarshal metadata: %v", body)  
if err := json.Unmarshal(body, &session.MetaData); err != nil {  
    logger.Errorf("failed to unmarshal introspect response: %v", err)  
    rw.WriteHeader(http.StatusInternalServerError)  
    return  
}

    logger.Debugf("set session: %v", session)  
ctx.SetSession(r, session, true)  
r.Header.Del("Authorization")

}

func main() {}

with: go mod init auth-check
go mod edit -replace github.com/jensneuse/graphql-go-tools=github.com/TykTechnologies/graphql-go-tools@140640759f4b
go get github.com/TykTechnologies/tyk@bda54b0f790c9bc11297c96fe8f2a5b370f39e05
go mod tidy
go mod vendor
docker run --rm -v pwd:/plugin-source tykio/tyk-plugin-compiler:v3.2.2 AuthCheck.so

check call : curl http://localhost:8080/hello
{"status":"pass","version":"v4.0.0","description":"Tyk GW","details":{"redis":{"status":"pass","componentType":"datastore","time":"2022-12-18T18:00:13Z"}}}

Actual behavior Everything is ok a startut, but when I call i get : http :8080/test-api/status/200 "Authorization:Bearer eyJ0eXAiOiJKV1QiLCJhbGciOiJSUzI1NiJ9...
HTTP/1.1 400 Bad Request
Content-Length: 109
Content-Type: application/json
Date: Sun, 18 Dec 2022 19:04:21 GMT
X-Generator: tyk.io

{
"error": "Session state is missing or unset! Please make sure that auth headers are properly applied"
}

Expected behavior The token is ok i shoud pas throught the auth and get a 200 from tky-demo

Logs (debug mode or log file): time="Dec 18 20:21:11" level=info msg="Tyk API Gateway v4.0.0" prefix=main
time="Dec 18 20:21:11" level=warning msg="Insecure configuration allowed" config.allow_insecure_configs=true prefix=checkup
time="Dec 18 20:21:11" level=warning msg="Default secret should be changed for production." config.secret=352d20ee67be67f6340b4c0605b044b7 prefix=checkup
time="Dec 18 20:21:11" level=debug msg="Notifier will not work in hybrid mode" prefix=main
time="Dec 18 20:21:11" level=debug msg="No Primary instance found, assuming control" prefix=host-check-mgr
time="Dec 18 20:21:11" level=info msg="Starting Poller" prefix=host-check-mgr
time="Dec 18 20:21:11" level=debug msg="---> Initialising checker" prefix=host-check-mgr
time="Dec 18 20:21:11" level=debug msg="[HOST CHECKER] Config:TriggerLimit: 3"
time="Dec 18 20:21:11" level=debug msg="[HOST CHECKER] Config:Timeout: ~10"
time="Dec 18 20:21:11" level=debug msg="[HOST CHECKER] Config:WorkerPool: 16"
time="Dec 18 20:21:11" level=debug msg="[HOST CHECKER] Init complete"
time="Dec 18 20:21:11" level=debug msg="---> Starting checker" prefix=host-check-mgr
time="Dec 18 20:21:11" level=debug msg="[HOST CHECKER] Starting..."
time="Dec 18 20:21:11" level=debug msg="[HOST CHECKER] Check loop started..."
time="Dec 18 20:21:11" level=debug msg="[HOST CHECKER] Host reporter started..."
time="Dec 18 20:21:11" level=debug msg="---> Checker started." prefix=host-check-mgr
time="Dec 18 20:21:11" level=info msg="PIDFile location set to: /var/run/tyk/tyk-gateway.pid" prefix=main
time="Dec 18 20:21:11" level=warning msg="The control_api_port should be changed for production" prefix=main
time="Dec 18 20:21:11" level=debug msg="Initialising default org store" prefix=main
time="Dec 18 20:21:11" level=info msg="Initialising Tyk REST API Endpoints" prefix=main time="Dec 18 20:21:11" level=debug msg="Connecting to redis cluster" time="Dec 18 20:21:11" level=debug msg="Creating new Redis connection pool" time="Dec 18 20:21:11" level=info msg="--> [REDIS] Creating single-node client" time="Dec 18 20:21:11" level=debug msg="Loaded API Endpoints" prefix=main time="Dec 18 20:21:11" level=info msg="--> Standard listener (http)" port=":8080" prefix=main
time="Dec 18 20:21:11" level=warning msg="Starting HTTP server on:[::]:8080" prefix=main
time="Dec 18 20:21:11" level=info msg="Initialising distributed rate limiter" prefix=main
time="Dec 18 20:21:11" level=debug msg="DRL: Setting node ID: solo-a3989922-b3ac-41cc-9580-97b4a36a1f35|06bc941fc2d5"
time="Dec 18 20:21:11" level=info msg="Tyk Gateway started (v4.0.0)" prefix=main
time="Dec 18 20:21:11" level=info msg="--> Listening on address: (open interface)" prefix=main
time="Dec 18 20:21:11" level=info msg="--> Listening on port: 8080" prefix=main
time="Dec 18 20:21:11" level=info msg="--> PID: 1" prefix=main
time="Dec 18 20:21:11" level=info msg="Starting gateway rate limiter notifications..." time="Dec 18 20:21:11" level=debug msg="Connecting to redis cluster" time="Dec 18 20:21:11" level=debug msg="Creating new Redis connection pool"
time="Dec 18 20:21:11" level=info msg="--> [REDIS] Creating single-node client" time="Dec 18 20:21:11" level=debug msg="Loaded API Endpoints" prefix=main
time="Dec 18 20:21:11" level=info msg="--> Standard listener (http)" port=":8080" prefix=main
time="Dec 18 20:21:11" level=warning msg="Starting HTTP server on:[::]:8080" prefix=main
time="Dec 18 20:21:11" level=info msg="Initialising distributed rate limiter" prefix=main
time="Dec 18 20:21:11" level=debug msg="DRL: Setting node ID: solo-a3989922-b3ac-41cc-9580-97b4a36a1f35|06bc941fc2d5"
time="Dec 18 20:21:11" level=info msg="Tyk Gateway started (v4.0.0)" prefix=main
time="Dec 18 20:21:11" level=info msg="--> Listening on address: (open interface)" prefix=main
time="Dec 18 20:21:11" level=info msg="--> Listening on port: 8080" prefix=main
time="Dec 18 20:21:11" level=info msg="--> PID: 1" prefix=main
time="Dec 18 20:21:11" level=info msg="Starting gateway rate limiter notifications..."
time="Dec 18 20:21:11" level=debug msg="Connecting to redis cluster"
time="Dec 18 20:21:11" level=debug msg="Creating new Redis connection pool"
time="Dec 18 20:21:11" level=info msg="--> [REDIS] Creating single-node client" time="Dec 18 20:21:11" level=debug msg="Connecting to redis cluster" time="Dec 18 20:21:11" level=debug msg="Creating new Redis connection pool" time="Dec 18 20:21:11" level=info msg="--> [REDIS] Creating single-node client" time="Dec 18 20:21:11" level=debug msg="Default JSVM timeout used: 5s" prefix=jsvm time="Dec 18 20:21:11" level=info msg="Loading policies" prefix=main time="Dec 18 20:21:11" level=info msg="Policies found (1 total):" prefix=main time="Dec 18 20:21:11" level=debug msg=" - default" prefix=main time="Dec 18 20:21:11" level=info msg="Loading API Specification from /opt/tyk-gateway/apps/api1.json" time="Dec 18 20:21:11" level=debug msg="Default JSVM timeout used: 5s" prefix=jsvm time="Dec 18 20:21:11" level=debug msg="Checking for transform paths..." time="Dec 18 20:21:11" level=debug msg="Checking for transform paths..." time="Dec 18 20:21:11" level=info msg="Detected 1 APIs" prefix=main time="Dec 18 20:21:11" level=info msg="Loading API configurations." prefix=main time="Dec 18 20:21:11" level=info msg="Tracking hostname" api_name="Test API" domain="(no host)" prefix=main time="Dec 18 20:21:11" level=info msg="Initialising Tyk REST API Endpoints" prefix=main time="Dec 18 20:21:11" level=debug msg="Loaded API Endpoints" prefix=main time="Dec 18 20:21:11" level=info msg="API bind on custom port:0" prefix=main time="Dec 18 20:21:11" level=debug msg="Initializing API" api_id=1 api_name="Test API" org_id=1 time="Dec 18 20:21:11" level=debug msg=Init api_id=1 api_name="Test API" mw=VersionCheck org_id=1 time="Dec 18 20:21:11" level=debug msg=Init api_id=1 api_name="Test API" mw=RateCheckMW org_id=1 time="Dec 18 20:21:11" level=debug msg=Init api_id=1 api_name="Test API" mw="GoPluginMiddleware: /opt/tyk-gateway/AuthCheck.so:AuthCheck" org_id=1 time="Dec 18 20:21:11" level=debug msg=Init api_id=1 api_name="Test API" mw=KeyExpired org_id=1 time="Dec 18 20:21:11" level=debug msg=Init api_id=1 api_name="Test API" mw=AccessRightsCheck org_id=1 time="Dec 18 20:21:11" level=debug msg=Init api_id=1 api_name="Test API" mw=GranularAccessMiddleware org_id=1 time="Dec 18 20:21:11" level=debug msg=Init api_id=1 api_name="Test API" mw=RateLimitAndQuotaCheck org_id=1 time="Dec 18 20:21:11" level=debug msg=Init api_id=1 api_name="Test API" mw=VersionCheck org_id=1 time="Dec 18 20:21:11" level=debug msg=Init api_id=1 api_name="Test API" mw=KeyExpired org_id=1 time="Dec 18 20:21:11" level=debug msg=Init api_id=1 api_name="Test API" mw=AccessRightsCheck org_id=1 time="Dec 18 20:21:11" level=debug msg="Rate limit endpoint is: /test-api/tyk/rate-limits" api_id=1 api_name="Test API" org_id=1 time="Dec 18 20:21:11" level=debug msg="Setting Listen Path: /test-api/" api_id=1 api_name="Test API" org_id=1 time="Dec 18 20:21:11" level=info msg="API Loaded" api_id=1 api_name="Test API" org_id=1 prefix=gateway server_name=-- user_id=-- user_ip=-- time="Dec 18 20:21:11" level=debug msg="Checker host list" prefix=main time="Dec 18 20:21:11" level=info msg="Loading uptime tests..." prefix=host-check-mgr time="Dec 18 20:21:11" level=debug msg="--- Setting tracking list up" prefix=host-check-mgr time="Dec 18 20:21:11" level=debug msg="Reset initiated" prefix=host-check-mgr time="Dec 18 20:21:11" level=debug msg="[HOST CHECKER] Checker reset queued!" time="Dec 18 20:21:11" level=debug msg="Checker host Done" prefix=main time="Dec 18 20:21:11" level=info msg="Initialised API Definitions" prefix=main time="Dec 18 20:21:11" level=info msg="API reload complete" prefix=main time="Dec 18 20:21:21" level=debug msg="Error trying to get value:redis: nil" time="Dec 18 20:21:21" level=debug msg="No Primary instance found, assuming control" prefix=host-check-mgr time="Dec 18 20:21:21" level=warning msg="Reconnecting storage: Redis is either down or was not configured" prefix=pub-sub time="Dec 18 20:21:22" level=debug msg="[HOST CHECKER] Host list reset" time="Dec 18 20:21:31" level=debug msg="Primary instance set, I am master" prefix=host-check-mgr time="Dec 18 20:21:37" level=debug msg=Started api_id=1 api_name="Test API" mw=VersionCheck org_id=1 origin=172.18.0.1 path="/test-api/status/200" ts=1671394897024957914 time="Dec 18 20:21:37" level=debug msg=Finished api_id=1 api_name="Test API" code=200 mw=VersionCheck ns=23009 org_id=1 origin=172.18.0.1 path="/test-api/status/200" time="Dec 18 20:21:37" level=debug msg=Started api_id=1 api_name="Test API" mw=RateCheckMW org_id=1 origin=172.18.0.1 path="/test-api/status/200" ts=1671394897024987842 time="Dec 18 20:21:37" level=debug msg=Finished api_id=1 api_name="Test API" code=200 mw=RateCheckMW ns=4823 org_id=1 origin=172.18.0.1 path="/test-api/status/200" time="Dec 18 20:21:37" level=debug msg=Started api_id=1 api_name="Test API" mw="GoPluginMiddleware: /opt/tyk-gateway/AuthCheck.so:AuthCheck" org_id=1 origin=172.18.0.1 path="/test-api/status/200" ts=167139489702 5008014 time="Dec 18 20:21:37" level=debug msg="Go-plugin request processing took" ms=63.068286 mwPath="/opt/tyk-gateway/AuthCheck.so" mwSymbolName=AuthCheck time="Dec 18 20:21:37" level=debug msg=Finished api_id=1 api_name="Test API" code=200 mw="GoPluginMiddleware: /opt/tyk-gateway/AuthCheck.so:AuthCheck" ns=63170685 org_id=1 origin=172.18.0.1 path="/test-api/statu s/200" time="Dec 18 20:21:37" level=debug msg=Started api_id=1 api_name="Test API" mw=KeyExpired org_id=1 origin=172.18.0.1 path="/test-api/status/200" ts=1671394897088225110 time="Dec 18 20:21:37" level=debug msg=Finished api_id=1 api_name="Test API" code=400 error="Session state is missing or unset! Please make sure that auth headers are properly applied" mw=KeyExpired ns=147621 org_id=1 origin=172.18.0.1 path="/test-api/status/200"

Lajule commented 1 year ago

Let me close the issue i switched everyting to 4.3.1 and it's works