Unable to introspect through oathkeeper reverse proxy

maxx · June 20, 2018, 12:33pm

Hello

I want to use “oauth2_introspection” authenticator handler to limit access to my custom api.

After several days of playing around I ended up with the following error:

oathkeeper-proxy_1  | time="2018-06-20T12:29:58Z" level=info msg="started handling request" method=GET remote="192.168.76.5:12336" request=/api/Values
hydra_1             | time="2018-06-20T12:29:58Z" level=info msg="started handling request" method=POST remote="172.19.249.121:55012" request=/oauth2/introspect
hydra_1             | time="2018-06-20T12:29:58Z" level=info msg="completed handling request" measure#http://localhost:4444.latency=327700 method=POST remote="172.19.249.121:55012" request=/oauth2/introspect status=200 text_status=OK took="327.7µs"
oathkeeper-proxy_1  | time="2018-06-20T12:29:58Z" level=warning msg="The authentication handler encountered an error" access_url="http://localhost:4455/api/Values" authentication_handler=oauth2_introspection error="json: cannot unmarshal string into Go struct field IntrospectionResponse.aud of type []string" granted=false reason_id=authentication_handler_error
oathkeeper-proxy_1  | time="2018-06-20T12:29:58Z" level=warning msg="Access request denied" access_url="http://localhost:4455/api/Values" error="json: cannot unmarshal string into Go struct field IntrospectionResponse.aud of type []string" granted=false
oathkeeper-proxy_1  | time="2018-06-20T12:29:58Z" level=error msg="An error occurred while handling a request" code=500 details="map[]" error="json: cannot unmarshal string into Go struct field IntrospectionResponse.aud of type []string" reason= request-id= status= trace="Stack trace: \ngithub.com/ory/oathkeeper/vendor/github.com/ory/keto/authentication.(*OAuth2IntrospectionAuthentication).Introspect\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/ory/keto/authentication/oauth2_introspection.go:173\ngithub.com/ory/oathkeeper/proxy.(*AuthenticatorOAuth2Introspection).Authenticate\n\t/go/src/github.com/ory/oathkeeper/proxy/authenticator_oauth2_introspection.go:68\ngithub.com/ory/oathkeeper/proxy.(*RequestHandler).HandleRequest\n\t/go/src/github.com/ory/oathkeeper/proxy/request_handler.go:99\ngithub.com/ory/oathkeeper/proxy.(*Proxy).Director\n\t/go/src/github.com/ory/oathkeeper/proxy/proxy.go:121\ngithub.com/ory/oathkeeper/proxy.(*Proxy).Director-fm\n\t/go/src/github.com/ory/oathkeeper/cmd/serve_proxy.go:213\nnet/http/httputil.(*ReverseProxy).ServeHTTP\n\t/usr/local/go/src/net/http/httputil/reverseproxy.go:169\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.Wrap.func1\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:46\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.HandlerFunc.ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:29\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.middleware.ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.(middleware).ServeHTTP-fm\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/oathkeeper/vendor/github.com/ory/metrics-middleware.(*MetricsManager).ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/ory/metrics-middleware/middleware.go:160\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.middleware.ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.(middleware).ServeHTTP-fm\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/oathkeeper/vendor/github.com/meatballhat/negroni-logrus.(*Middleware).ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/meatballhat/negroni-logrus/middleware.go:136\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.middleware.ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.(*Negroni).ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:96\ngithub.com/ory/oathkeeper/vendor/github.com/rs/cors.(*Cors).Handler.func1\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/rs/cors/cors.go:200\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:1947\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:2694\nnet/http.(*conn).serve\n\t/usr/local/go/src/net/http/server.go:1830\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:2361" writer=JSON
oathkeeper-proxy_1  | time="2018-06-20T12:29:58Z" level=info msg="completed handling request" measure#oathkeeper-proxy.latency=11641500 method=GET remote="192.168.76.5:12336" request=/api/Values status=500 text_status="Internal Server Error" took=11.6415ms

The error itself is: json: cannot unmarshal string into Go struct field IntrospectionResponse.aud of type []string

Any ideas?

hackerman · June 21, 2018, 9:33am

Please share some details, what configuration are you using (environment variables), what access rules do you have defined, what request are you making (show the e.g. curl command). Thanks!

maxx · June 21, 2018, 11:19am

Thanks for response.

Everything below is supposed to run on windows (of course you may use linux, just change command syntax)

This is docker compose file:

version: '2.4'

services:
    hydra:
        image: oryd/hydra
        ports:
            - "4444:4444"
        platform: linux
        environment:
            - LOG_LEVEL=debug
            - DATABASE_URL=memory
            - SYSTEM_SECRET=changemechangemechangemechangeme
            - ISSUER_URL=http://localhost:4444/
            - FORCE_ROOT_CLIENT_CREDENTIALS=admin:demo-password
            - ACCESS_TOKEN_LIFESPAN=24h
            - OAUTH2_SHARE_ERROR_DEBUG=1
        volumes:
            - ./data:/shared-data
        entrypoint: hydra
        command:
          host --dangerous-force-http

    oathkeeper-api:
        image: oryd/oathkeeper
        depends_on:
            - hydra
        ports:
            - "4456:4456"
        platform: linux
        environment:
            - LOG_LEVEL=debug
            - DATABASE_URL=memory
            - PORT=4456
            - CREDENTIALS_ISSUER_ID_TOKEN_HS256_SECRET=changemechangemechangemechangeme
        volumes:
          - ./data:/shared-data
        command:
          serve api
    
    oathkeeper-proxy:
        image: oryd/oathkeeper
        depends_on:
            - oathkeeper-api
        ports:
            - "4455:4455"
        platform: linux
        environment:
            - LOG_LEVEL=debug
            - DATABASE_URL=memory
            - PORT=4455
            - OATHKEEPER_API_URL=http://oathkeeper-api:4456
            - CREDENTIALS_ISSUER_ID_TOKEN_HS256_SECRET=changemechangemechangemechangemedo
            - AUTHENTICATOR_OAUTH2_INTROSPECTION_CLIENT_ID=oathkeeper-client
            - AUTHENTICATOR_OAUTH2_INTROSPECTION_CLIENT_SECRET=something-secure
            - AUTHENTICATOR_OAUTH2_INTROSPECTION_TOKEN_URL=http://hydra:4444/oauth2/token
            - AUTHENTICATOR_OAUTH2_INTROSPECTION_INTROSPECT_URL=http://hydra:4444/oauth2/introspect
        volumes:
          - ./data:/shared-data
        command:
          serve proxy

api-client.json (usual API user, used in user-curl-script)

{
  "id": "api-client",
  "client_secret": "api-secret",
  "scope": "scope-api offline",
  "grant_types": ["authorization_code", "client_credentials", "refresh_token"],
  "response_types": ["code", "token"]
}

oathkeeper-client.json (client for oathkeeper)

{
  "id": "oathkeeper-client",
  "client_secret": "something-secure",
  "scope": "hydra.introspect offline",
  "grant_types": ["client_credentials"],
  "response_types": ["token"]
}

policy.json

{
  "subjects": ["oathkeeper-client"],
  "effect": "allow",
  "resources": [
    "rn:hydra:keys:oathkeeper:id-token<.*>",
    "rn:hydra:warden:<.*>",
    "rn:hydra:oauth2:tokens"
  ],
  "actions": [
    "decide",
    "get",
    "create",
    "introspect",
    "update",
    "delete"
  ]
}

rules.json

[
{
    "id": "id-test-ap",
    "upstream": {
        "url": "http://192.168.76.5:8088"
    },
    "match": {
        "url": "http://localhost:4455/<.*>",
        "methods": [
            "GET"
        ]
    },
    "authenticators": [
	{ 
		"handler": "oauth2_introspection" ,
		"config": {
        	    "required_scope": ["scope-api"]
        	}
	}
	],
    "authorizer": {
	 "handler": "allow"
	},
    "credentials_issuer": {
  	 "handler": "noop"
	}
}
]

I have ASP.NET simple Rest API that sits on http://192.168.76.5:8088, this is subject to change, but for my test purposes it works fine.

These lines are supposed to populate hydra with clients and policy

docker exec -i -t authenticate-tests_hydra_1 hydra connect --url http://localhost:4444 --id admin --secret demo-password
docker exec -i -t authenticate-tests_hydra_1 hydra clients import /shared-data/oathkeeper-client.json /shared-data/api-client.json --skip-tls-verify
docker exec -i -t authenticate-tests_hydra_1 hydra policies create -f /shared-data/policy.json --skip-tls-verify

Update oathkeeper rules:

docker exec -i -t authenticate-tests_oathkeeper-proxy_1  oathkeeper rules import /shared-data/rules.json --endpoint http://authenticate-tests_oathkeeper-api_1:4456

Obtain token:

curl -v -k -d "@token.txt" -H "Content-Type: application/x-www-form-urlencoded" -H "Authorization: Basic YXBpLWNsaWVudDphcGktc2VjcmV0" -X POST http://localhost:4444/oauth2/token

token.txt:

client_id=api-client&client_secret=api-secret&grant_type=client_credentials&scope=scope-api%20offline

Call API with following command: (you need to replace token with the one from prev. command. Please note, that I am using http://localhost:4455 URL (that’s where oathkeeper lives)

curl -v -k -H "Authorization:bearer 5ebu_We5-MRMuIebyES5el_oMdtuaaieU13WX6DqiBw.3rQy6PAosIS-PT58cqq5Afsa1ZFpHz3B55ntJN8jeJs" -X GET http://localhost:4455/api/Values

And get the followint result:

* Curl_addHandleToPipeline: length: 1
* - Conn 0 (0x2995cf0) send_pipe: 1, recv_pipe: 0
* About to connect() to localhost port 4455 (#0)
*   Trying ::1...
* Connection refused
*   Trying 127.0.0.1...
* Connected to localhost (127.0.0.1) port 4455 (#0)
> GET /api/Values HTTP/1.1
> User-Agent: curl/7.33.0
> Host: localhost:4455
> Accept: */*
> Authorization:bearer 5ebu_We5-MRMuIebyES5el_oMdtuaaieU13WX6DqiBw.3rQy6PAosIS-PT58cqq5Afsa1ZFpHz3B55ntJN8jeJs
>
< HTTP/1.1 500 Internal Server Error
< Content-Type: application/json
< Vary: Origin
< Date: Thu, 21 Jun 2018 11:11:38 GMT
< Content-Length: 129
<
{"error":{"code":500,"message":"json: cannot unmarshal string into Go struct field IntrospectionResponse.aud of type []s
tring"}}
* Connection #0 to host localhost left intact

Thanks

PS
I used these scripts for experiments, I think there are a lot of garbage in configs:(

hackerman · June 21, 2018, 1:00pm

Thanks, one more thing, could you please set LOG_LEVEL=debug in the respective services and show the result of docker log <container-id>? It should include a stack trace which will help chase down the cause.

ps: Seems like the log level is set already, so only the logs are needed.

maxx · June 21, 2018, 1:29pm

Please take a look
In this scenario after starting composer I did the following:

Configured hydra (add users, policy)

docker exec -i -t authenticate-tests_hydra_1 hydra connect --url http://localhost:4444 --id admin --secret demo-password
docker exec -i -t authenticate-tests_hydra_1 hydra clients import /shared-data/oathkeeper-client.json /shared-data/api-client.json --skip-tls-verify
docker exec -i -t authenticate-tests_hydra_1 hydra policies create -f /shared-data/policy.json --skip-tls-verify

imported rules into oathkeeper

docker exec -i -t authenticate-tests_oathkeeper-proxy_1  oathkeeper rules import /shared-data/rules.json --endpoint http://authenticate-tests_oathkeeper-api_1:4456

obtain client token from hydra:

curl -v -k -d "@token.txt" -H "Content-Type: application/x-www-form-urlencoded" -H "Authorization: Basic YXBpLWNsaWVudDphcGktc2VjcmV0" -X POST http://localhost:4444/oauth2/token

Tried to use API

curl -v -k -H "IzDq0s9To1To6tqPMUDaTAhep--ZS_K9NqN5D9fBs9M.htNAZw6sS8BLFjKA_IXWijxovI3JUqpWq7qqMVnBsbc" -X GET http://localhost:4455/api/Values

Logs from all containers:

Attaching to authenticate-tests_hydra_1, authenticate-tests_oathkeeper-api_1, authenticate-tests_oathkeeper-proxy_1
hydra_1             | time="2018-06-21T13:16:56Z" level=info msg="DATABASE_URL set to memory, connecting to ephermal in-memory database."
hydra_1             | time="2018-06-21T13:16:56Z" level=info msg="Key pair for signing hydra.openid.id-token is missing. Creating new one."
hydra_1             | time="2018-06-21T13:16:58Z" level=info msg="Setting up telemetry - for more information please visit https://ory.gitbooks.io/hydra/content/telemetry.html"
hydra_1             | time="2018-06-21T13:16:58Z" level=warning msg="No clients were found. Creating a temporary root client..."
hydra_1             | time="2018-06-21T13:16:58Z" level=info msg="Temporary root client created."
hydra_1             | time="2018-06-21T13:16:58Z" level=warning msg="No TLS Key / Certificate for HTTPS found. Generating self-signed certificate."
hydra_1             | time="2018-06-21T13:16:58Z" level=info msg="Setting up http server on :4444"
hydra_1             | time="2018-06-21T13:16:58Z" level=warning msg="HTTPS disabled. Never do this in production."
oathkeeper-api_1    | time="2018-06-21T13:16:58Z" level=info msg="Transmission of telemetry data is enabled, to learn more go to: https://www.ory.sh/docs/guides/latest/telemetry/"
oathkeeper-api_1    | time="2018-06-21T13:16:58Z" level=info msg="Listening on :4456"
oathkeeper-api_1    | time="2018-06-21T13:16:58Z" level=info msg="Detected local environment, skipping telemetry commit"
oathkeeper-api_1    | time="2018-06-21T13:16:58Z" level=info msg="Detected local environment, skipping telemetry commit"
oathkeeper-api_1    | time="2018-06-21T13:17:00Z" level=info msg="started handling request" method=GET remote="172.29.160.57:54710" request="/rules?limit=50000&offset=0"
oathkeeper-api_1    | time="2018-06-21T13:17:00Z" level=info msg="completed handling request" measure#oathkeeper-api.latency=265900 method=GET remote="172.29.160.57:54710" request="/rules?limit=50000&offset=0" status=200 text_status=OK took="265.9µs"
oathkeeper-proxy_1  | time="2018-06-21T13:17:00Z" level=info msg="Transmission of telemetry data is enabled, to learn more go to: https://www.ory.sh/docs/guides/latest/telemetry/"
oathkeeper-proxy_1  | time="2018-06-21T13:17:00Z" level=info msg="Listening on :4455.\n"
oathkeeper-proxy_1  | time="2018-06-21T13:17:00Z" level=info msg="Detected local environment, skipping telemetry commit"
oathkeeper-proxy_1  | time="2018-06-21T13:17:00Z" level=info msg="Detected local environment, skipping telemetry commit"
hydra_1             | time="2018-06-21T13:17:24Z" level=info msg="started handling request" method=POST remote="127.0.0.1:52736" request=/oauth2/token
hydra_1             | time="2018-06-21T13:17:24Z" level=info msg="completed handling request" measure#http://localhost:4444.latency=56612600 method=POST remote="127.0.0.1:52736" request=/oauth2/token status=200 text_status=OK took=56.6126ms
hydra_1             | time="2018-06-21T13:17:24Z" level=info msg="started handling request" method=GET remote="127.0.0.1:52736" request=/
hydra_1             | time="2018-06-21T13:17:24Z" level=info msg="completed handling request" measure#http://localhost:4444.latency=55000 method=GET remote="127.0.0.1:52736" request=/ status=404 text_status="Not Found" took="55µs"
hydra_1             | time="2018-06-21T13:17:24Z" level=info msg="started handling request" method=POST remote="127.0.0.1:52738" request=/clients
hydra_1             | time="2018-06-21T13:17:24Z" level=info msg="Access granted" client_id=admin request="&{[] [] { 2018-06-21 13:17:24.6148484 +0000 UTC m=+28.054441401 0xc4203c2500 [hydra hydra.*] [hydra hydra.*] map[grant_type:[client_credentials] scope:[hydra hydra.*]] 0xc4201740e0}}" result="&{admin [hydra hydra.*] http://localhost:4444 admin 2018-06-21 13:17:24.6148484 +0000 UTC m=+28.054441401 2018-06-22 13:17:24.6710316 +0000 UTC m=+86428.110624601 map[]}" subject=admin
hydra_1             | time="2018-06-21T13:17:24Z" level=info msg="completed handling request" measure#http://localhost:4444.latency=56741000 method=POST remote="127.0.0.1:52738" request=/clients status=201 text_status=Created took=56.741ms
hydra_1             | time="2018-06-21T13:17:24Z" level=info msg="started handling request" method=POST remote="127.0.0.1:52738" request=/clients
hydra_1             | time="2018-06-21T13:17:24Z" level=info msg="Access granted" client_id=admin request="&{[] [] { 2018-06-21 13:17:24.6148484 +0000 UTC m=+28.054441401 0xc4203c2500 [hydra hydra.*] [hydra hydra.*] map[grant_type:[client_credentials] scope:[hydra hydra.*]] 0xc4201740e0}}" result="&{admin [hydra hydra.*] http://localhost:4444 admin 2018-06-21 13:17:24.6148484 +0000 UTC m=+28.054441401 2018-06-22 13:17:24.6710316 +0000 UTC m=+86428.110624601 map[]}" subject=admin
hydra_1             | time="2018-06-21T13:17:24Z" level=info msg="completed handling request" measure#http://localhost:4444.latency=55909500 method=POST remote="127.0.0.1:52738" request=/clients status=201 text_status=Created took=55.9095ms
hydra_1             | time="2018-06-21T13:17:25Z" level=info msg="started handling request" method=POST remote="127.0.0.1:52740" request=/oauth2/token
hydra_1             | time="2018-06-21T13:17:25Z" level=info msg="completed handling request" measure#http://localhost:4444.latency=55654900 method=POST remote="127.0.0.1:52740" request=/oauth2/token status=200 text_status=OK took=55.6549ms
hydra_1             | time="2018-06-21T13:17:25Z" level=info msg="started handling request" method=GET remote="127.0.0.1:52740" request=/
hydra_1             | time="2018-06-21T13:17:25Z" level=info msg="completed handling request" measure#http://localhost:4444.latency=67000 method=GET remote="127.0.0.1:52740" request=/ status=404 text_status="Not Found" took="67µs"
hydra_1             | time="2018-06-21T13:17:25Z" level=info msg="started handling request" method=POST remote="127.0.0.1:52742" request=/policies
hydra_1             | time="2018-06-21T13:17:25Z" level=info msg="Access granted" client_id=admin request="&{[] [] { 2018-06-21 13:17:25.0402841 +0000 UTC m=+28.479877101 0xc420144600 [hydra hydra.*] [hydra hydra.*] map[grant_type:[client_credentials] scope:[hydra hydra.*]] 0xc420174b60}}" result="&{admin [hydra hydra.*] http://localhost:4444 admin 2018-06-21 13:17:25.0402841 +0000 UTC m=+28.479877101 2018-06-22 13:17:25.0958166 +0000 UTC m=+86428.535409601 map[]}" subject=admin
hydra_1             | time="2018-06-21T13:17:25Z" level=info msg="completed handling request" measure#http://localhost:4444.latency=290300 method=POST remote="127.0.0.1:52742" request=/policies status=201 text_status=Created took="290.3µs"
oathkeeper-api_1    | time="2018-06-21T13:17:25Z" level=info msg="started handling request" method=GET remote="172.29.160.57:54720" request="/rules?limit=50000&offset=0"
oathkeeper-api_1    | time="2018-06-21T13:17:25Z" level=info msg="completed handling request" measure#oathkeeper-api.latency=345500 method=GET remote="172.29.160.57:54720" request="/rules?limit=50000&offset=0" status=200 text_status=OK took="345.5µs"
oathkeeper-api_1    | time="2018-06-21T13:17:30Z" level=info msg="started handling request" method=GET remote="172.29.160.57:54722" request="/rules?limit=50000&offset=0"
oathkeeper-api_1    | time="2018-06-21T13:17:30Z" level=info msg="completed handling request" measure#oathkeeper-api.latency=229800 method=GET remote="172.29.160.57:54722" request="/rules?limit=50000&offset=0" status=200 text_status=OK took="229.8µs"
oathkeeper-api_1    | time="2018-06-21T13:17:32Z" level=info msg="started handling request" method=GET remote="172.29.160.57:54724" request=/rules/id-test-ap
oathkeeper-api_1    | time="2018-06-21T13:17:32Z" level=error msg="An error occurred while handling a request" code=404 details="map[]" error="The requested resource could not be found" reason= request-id= status="Not Found" trace="Stack trace: \ngithub.com/ory/oathkeeper/rule.(*MemoryManager).GetRule\n\t/go/src/github.com/ory/oathkeeper/rule/manager_memory.go:50\ngithub.com/ory/oathkeeper/rule.(*Handler).Get\n\t/go/src/github.com/ory/oathkeeper/rule/handler.go:149\ngithub.com/ory/oathkeeper/rule.(*Handler).Get-fm\n\t/go/src/github.com/ory/oathkeeper/rule/handler.go:54\ngithub.com/ory/oathkeeper/vendor/github.com/julienschmidt/httprouter.(*Router).ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/julienschmidt/httprouter/router.go:299\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.Wrap.func1\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:46\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.HandlerFunc.ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:29\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.middleware.ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.(middleware).ServeHTTP-fm\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/oathkeeper/vendor/github.com/ory/metrics-middleware.(*MetricsManager).ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/ory/metrics-middleware/middleware.go:160\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.middleware.ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.(middleware).ServeHTTP-fm\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/oathkeeper/vendor/github.com/meatballhat/negroni-logrus.(*Middleware).ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/meatballhat/negroni-logrus/middleware.go:136\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.middleware.ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.(*Negroni).ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:96\ngithub.com/ory/oathkeeper/vendor/github.com/rs/cors.(*Cors).Handler.func1\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/rs/cors/cors.go:200\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:1947\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:2694\nnet/http.(*conn).serve\n\t/usr/local/go/src/net/http/server.go:1830\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:2361" writer=JSON
oathkeeper-api_1    | time="2018-06-21T13:17:32Z" level=info msg="completed handling request" measure#oathkeeper-api.latency=926600 method=GET remote="172.29.160.57:54724" request=/rules/id-test-ap status=404 text_status="Not Found" took="926.6µs"
oathkeeper-api_1    | time="2018-06-21T13:17:32Z" level=info msg="started handling request" method=PUT remote="172.29.160.57:54726" request=/rules/id-test-ap
oathkeeper-proxy_1  | time="2018-06-21T13:19:59Z" level=info msg="started handling request" method=GET remote="192.168.76.5:7513" request=/api/Values
oathkeeper-proxy_1  | time="2018-06-21T13:19:59Z" level=warning msg="No authentication handler was responsible for handling the authentication request" access_url="http://localhost:4455/api/Values" error="Access credentials are either expired or missing a scope" granted=false reason_id=authentication_handler_no_match
oathkeeper-proxy_1  | time="2018-06-21T13:19:59Z" level=warning msg="Access request denied" access_url="http://localhost:4455/api/Values" error="Access credentials are either expired or missing a scope" granted=false
oathkeeper-proxy_1  | time="2018-06-21T13:19:59Z" level=error msg="An error occurred while handling a request" code=401 details="map[]" error="Access credentials are either expired or missing a scope" reason= request-id= status=Unauthorized trace="Stack trace: \ngithub.com/ory/oathkeeper/proxy.(*RequestHandler).HandleRequest\n\t/go/src/github.com/ory/oathkeeper/proxy/request_handler.go:126\ngithub.com/ory/oathkeeper/proxy.(*Proxy).Director\n\t/go/src/github.com/ory/oathkeeper/proxy/proxy.go:121\ngithub.com/ory/oathkeeper/proxy.(*Proxy).Director-fm\n\t/go/src/github.com/ory/oathkeeper/cmd/serve_proxy.go:213\nnet/http/httputil.(*ReverseProxy).ServeHTTP\n\t/usr/local/go/src/net/http/httputil/reverseproxy.go:169\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.Wrap.func1\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:46\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.HandlerFunc.ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:29\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.middleware.ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.(middleware).ServeHTTP-fm\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/oathkeeper/vendor/github.com/ory/metrics-middleware.(*MetricsManager).ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/ory/metrics-middleware/middleware.go:160\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.middleware.ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.(middleware).ServeHTTP-fm\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/oathkeeper/vendor/github.com/meatballhat/negroni-logrus.(*Middleware).ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/meatballhat/negroni-logrus/middleware.go:136\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.middleware.ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:38\ngithub.com/ory/oathkeeper/vendor/github.com/urfave/negroni.(*Negroni).ServeHTTP\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/urfave/negroni/negroni.go:96\ngithub.com/ory/oathkeeper/vendor/github.com/rs/cors.(*Cors).Handler.func1\n\t/go/src/github.com/ory/oathkeeper/vendor/github.com/rs/cors/cors.go:200\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:1947\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:2694\nnet/http.(*conn).serve\n\t/usr/local/go/src/net/http/server.go:1830\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:2361" writer=JSON
oathkeeper-proxy_1  | time="2018-06-21T13:19:59Z" level=info msg="completed handling request" measure#oathkeeper-proxy.latency=2372200 method=GET remote="192.168.76.5:7513" request=/api/Values status=401 text_status=Unauthorized took=2.3722ms

I removed some log messages from oathkeeper-api container that stands for pooling rules like these
... request="/rules?limit=50000&offset=0 ...

hackerman · June 21, 2018, 2:36pm

Ok, I think I know what the issue is. You must make sure that the versions in your docker-compose.yml match. Right now, you’re not defining a version constraint so the latest image will be downloaded. So right now, you’re probably mixing incompatible versions.

Instead, define the docker images like this: image: ory/hydra:v1.0.0-beta.4

hackerman · June 21, 2018, 2:37pm

Also it seems like you’re using an ORY Hydra version prior to 1.0.0-beta which is incompatible to the 1.0.0 branch of ORY Oathkeeper. Try to run all services in the same version, so oryd/hydra:v1.0.0-beta.4, oryd/oathkeeper:v1.0.0-beta.4, oryd/keto:v1.0.0-beta.4.

maxx · June 22, 2018, 12:10pm

Thanks
I am trying to put all these things together

I’m not sure if I understand all things in a right way.
When using oauth2_introspection authenticator, do I need to run keto??
I don’t see any env variables that should point to keto in this scenario.

maxx · June 22, 2018, 1:34pm

Finally I got it running, Thanks!

There is one thing left:
I cannot obtain “refresh_token” in any case.
Of course I have offline scope in my client definition:

"scope": "scope-api offline"

as well as I am obtaining my token using offline scope, like this:

client_id=api-client&client_secret=api-secret&grant_type=client_credentials&scope=scope-api%20offline

but I am receiving only access_token

(later on)
Found that this is impossible https://tools.ietf.org/html/rfc6749#section-4.4

hackerman · June 24, 2018, 12:20pm

The client_credentials grant does not get a refresh token You can refresh it without user interaction by re-requesting the client_credentials grant.

stevepnscott · July 30, 2020, 1:29pm

Hi @hackerman

I am having exactly the same issue - using Keycloak to provide an introspeciton endpoint.

Monitoring the network resposne I am getting this back from the introspection endpoint:
{
“exp”: 1596054756,
“nbf”: 0,
“iat”: 1596054456,
“jti”: “581fb000-8fd9-4323-85c0-c0c8405f7c35”,
“aud”: “account”,
“typ”: “Bearer”,
“acr”: “1”,
“active”: true
}

just following up on this as I am seeing the same error in the oathkeeper logs when calling out to keycloak;

{“error”:{“code”:500,“message”:“json: cannot unmarshal string into Go struct field AuthenticatorOAuth2IntrospectionResult.aud of type []string”}}

Keycloak can return a single string or an array depending on the number of audiences defined.

The RFC I think supports thids approach, shoud Oathkeeper support single strings also ?

I have a work around by adding additional audience values to the token response, but this should not be necessary.

hackerman · July 30, 2020, 2:16pm

Yes, I think this was also resolved but not sure - what version do you use?

stevepnscott · July 30, 2020, 2:24pm

I was using : v0.38.2-beta.1 from 2 months ago, let me pull latest and see if there is any difference.

Thanks.

stevepnscott · July 30, 2020, 2:31pm

I just pulled latest and built using :

docker build -t ory-oathkeeper-demo .

— dockerfile —
FROM oryd/oathkeeper:latest

ADD config.yaml /config.yaml

ADD rules.json /rules.json

ADD jwks.json /jwks.json

— images –

Stephens-MBP:Oathkeeper stephenscott$ docker image ls
REPOSITORY TAG IMAGE ID CREATED SIZE
ory-oathkeeper-demo latest fcc88f4842ea 5 minutes ago 19.2MB
oryd/oathkeeper latest 4cbb9c1f1ddd 29 hours ago 19.2MB

stevepnscott · July 30, 2020, 2:32pm

Getting the same issue :

{“error”:{“code”:500,“status”:“Internal Server Error”,“message”:“json: cannot unmarshal string into Go struct field AuthenticatorOAuth2IntrospectionResult.aud of type []string”}}

hackerman · July 30, 2020, 2:46pm

Would you mind opening an issue in ORY Oathkeeper with all the info? Thank you!

stevepnscott · July 30, 2020, 3:53pm

Sure - done : https://github.com/ory/oathkeeper/issues/491

hackerman · July 31, 2020, 9:12am

Thank you!