Upstream not being redirected correctly after oathkeeper approval

[Atharex]

Describe the bug

I am running an internal service on kubernetes, behind an Ambassador API gateway, itself behind a Traefik ingress controller.
The service endpoint has an associated AuthService, connected to an Oathkeeper instance. The access rule to the service is created with a CRD by Oathkeeper-maester and uses the Oauth2 introspection workflow.

The oathkeeper token authentication seems to succeed, as I see the request going to oathkeeper and back to the api gateway. This happens when I correctly issue an active token with a proper header

However for some reason the redirect to the upstream URL seems not to work and I get a 404 with a message that the Request URL does not match any rules (why should an upstream match the access rule url?) and in the one before last line it seems the same request is granted, but still returns a 404. Why could this be happening? My configurations are pasted below

I invoke the request with curl like so:
>>> curl -k -X POST -H "Special-Authorization: <token>" https://<service>/my/service/url

Environment

• Version: Oathkeeper Helm Chart v0.5.0
• Environment: Kubernetes

Oathkeeper Logs

192.168.235.133 is the traefik ingress controller
192.168.235.134 is the ambassador API gateway
192.168.235.149 is the oathkeeper proxy

kubectl logs -f oathkeeper-9d58d87cb-9mk44
time=2021-01-12T17:33:17Z level=info msg=Config file loaded successfully. audience=application path=/etc/config/config.yaml service_name=oathkeeper service_version=
time=2021-01-13T14:41:34Z level=info msg=started handling request http_request=map[headers:map[user-agent:curl/7.47.0 x-forwarded-for:172.16.0.1,192.168.235.133,192.168.235.134 x-forwarded-proto:http] host:<service> method:POST path:/my/service/url query:<nil> remote:192.168.235.134:42154 scheme:http]
time=2021-01-13T14:41:34Z level=info msg=started handling request http_request=map[headers:map[user-agent:curl/7.47.0 x-forwarded-for:172.16.0.1,192.168.235.133,192.168.235.134, 192.168.235.134,192.168.235.149,192.168.235.134 x-forwarded-proto:http] host:<internal-service> method:POST path:/my/service/url query:<nil> remote:192.168.235.134:41962 scheme:http]
time=2021-01-13T14:41:34Z level=warning msg=Access request denied audience=application error=map[debug: message:Requested url does not match any rules reason: status:Not Found status_code:404] granted=false http_host=<internal-service> http_method=POST http_url=http://<internal-service>/my/service/url http_user_agent=curl/7.47.0 service_name=ORY Oathkeeper service_version=v0.38.5-beta.1
time=2021-01-13T14:41:34Z level=error msg=An error occurred while handling a request code=404 debug= details=map[] error=The requested resource could not be found reason= request-id= status=404 writer=JSON
time=2021-01-13T14:41:34Z level=info msg=completed handling request http_request=map[headers:map[user-agent:curl/7.47.0 x-forwarded-for:172.16.0.1,192.168.235.133,192.168.235.134, 192.168.235.134,192.168.235.149,192.168.235.134 x-forwarded-proto:http] host:<intetrnal-service> method:POST path:/my/service/url query:<nil> remote:192.168.235.134:41962 scheme:http] http_response=map[status:404 text_status:Not Found took:240.919µs]
time=2021-01-13T14:41:34Z level=warning msg=Access request granted audience=application granted=true http_host=<internal-service> http_method=POST http_url=http://<internal-service>/my/service/url http_user_agent=curl/7.47.0 service_name=ORY Oathkeeper service_version=v0.38.5-beta.1 subject=49785d49-b906-4c2e-b4b9-e32e640a5a14
time=2021-01-13T14:41:34Z level=info msg=completed handling request http_request=map[headers:map[user-agent:curl/7.47.0 x-forwarded-for:172.16.0.1,192.168.235.133,192.168.235.134 x-forwarded-proto:http] host:<service> method:POST path:/my/service/url query:<nil> remote:192.168.235.134:42154 scheme:http] http_response=map[status:404 text_status:Not Found took:2.075309ms]

Authservice:

---
apiVersion: getambassador.io/v2
kind: AuthService
metadata:
  name: api-gateway-authentication
  namespace: ory-auth
spec:
  auth_service: "http://oathkeeper-proxy.ory-auth.svc.cluster.local:4455"
  tls: false
  proto: http
  timeout_ms: 5000
  status_on_error:
    code: 403
  failure_mode_allow: false

Access rule

---
apiVersion: oathkeeper.ory.sh/v1alpha1
kind: Rule
metadata:
  name: test-access
  namespace: ory-auth
spec:
  upstream:
    url: http://<internal-service>
    preserveHost: false
  match:
    url: http://<service>/my/service/url
    methods:
      - GET
      - POST
  authenticators:
    - handler: oauth2_introspection
      config:
        introspection_url: http://hydra-admin.ory-auth.svc.cluster.local:4445/oauth2/introspect
  mutators:
  - handler: noop
  authorizer:
    handler: allow

[zepatrik]

I don't know if that is a copy/paste error, but in your curl command you are using https while the rule matches http. Check if you are using the same protocol in both places 😉

[Atharex]

The reason I call with https is because my ingress controller enforces https and is doing ssl termination.

I also tried if I can match the access rule on https, but it seems oathkeeper only passes through http.
When the access rule matches on https, the logs show no line that the access is granted (which is shown on http)

time=2021-01-14T08:07:35Z level=info msg=started handling request http_request=map[headers:map[user-agent:curl/7.47.0 x-forwarded-for:172.16.0.1,192.168.235.133,192.168.235.134 x-forwarded-proto:http] host:<service> method:POST path:/my/service/url query:<nil> remote:192.168.235.134:54326 scheme:http]
time=2021-01-14T08:07:35Z level=warning msg=Access request denied audience=application error=map[debug: message:Requested url does not match any rules reason: status:Not Found status_code:404] granted=false http_host=<service> http_method=POST http_url=http://<service>/my/service/url http_user_agent=curl/7.47.0 service_name=ORY Oathkeeper service_version=v0.38.5-beta.1
time=2021-01-14T08:07:35Z level=error msg=An error occurred while handling a request code=404 debug= details=map[] error=The requested resource could not be found reason= request-id= status=404 writer=JSON
time=2021-01-14T08:07:35Z level=info msg=completed handling request http_request=map[headers:map[user-agent:curl/7.47.0 x-forwarded-for:172.16.0.1,192.168.235.133,192.168.235.134 x-forwarded-proto:http] host:<service> method:POST path:/my/service/url query:<nil> remote:192.168.235.134:54326 scheme:http] http_response=map[status:404 text_status:Not Found took:1.809619ms]

Someone mentioned he used only http in a similar case: (and somehow got it working that way)
#153

[zepatrik]

Right. I am a bit confused from the first logs you posted. There are actually two requests from ambassador, one going to <internal-service> and one to <service>. The one going to <service> seems to be matched and granted, but there is no rule for <internal-service> that could be matched against. That missing rule is reported. Can you confirm this is actually what is happening?

[Atharex]

That is exactly the case!

I am also confused where 2 requests are coming from and why would oathkeeper want to match the url, as it is only configured as an upstream in the access rule.

[zepatrik]

I assume there is a problem with ambassador or the routing in general, that causes these issues. The request is coming from ambassador and therefore I recommend you have a look there. Is Oathkeeper able to reach <internal-service> directly or is that routed through the ingress again? If you find the issue please leave a comment here to help other people.
Oathkeeper is doing exactly what it is configured to do (your one rule) so I don't see any bug there.

[Atharex]

Thanks @zepatrik that was the hint I needed (that it probably isn't the oathkeeper config) now I've made it work!

The issue was with the upstream in the rule. I was pointing it to the ambassador URL of the upstream service, so after the first rule succeeded, it returned to ambassador and triggered another round of authentication with the upstream service, which of course failed.

All I needed to do, was to point my upstream directly to the service and not the URL under which it was served under ambassador.

I also had to patch my auth service slightly, because I needed to pass JSON data to the upstream service after authentication

---
apiVersion: getambassador.io/v2
kind: AuthService
metadata:
  name: api-gateway-authentication
  namespace: ory-auth
spec:
  auth_service: "http://oathkeeper-proxy.ory-auth.svc.cluster.local:4455"
  tls: false
  proto: http
  timeout_ms: 5000
  status_on_error:
    code: 403
  failure_mode_allow: false
  include_body:
    max_bytes: 4096  ## the upstream is a microservice expecting JSON data, so the body needs to be included 
    allow_partial: true
  allowed_request_headers:  
  - "Content-Type"   ## A header the microservice is relying on 

[zepatrik]

Awesome, glad you figured it out.