Unable to introspect through oathkeeper reverse proxy


#1

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?


#2

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!


#3

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:(


#4

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.


#5

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

  1. 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
  1. 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
  1. 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
  1. 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 ...


#6

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


#7

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.


#8

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.


#9

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 :frowning:

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


#10

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