rest-authz-resource-server: denied requests cause another request to /error resource

[pauko]

Describe the bug

When studying the DEBUG log messages of the PolicyEnforcer used in rest-authz-resource-server, I realized that whenever the policy enforcer denies a request to any of the sample resources at http://localhost:8080 or http://localhost:8080/protected/premium, another HTTP request for some resource /error is dispatched causing yet another iteration of the Security Filter Chain of PolicyEnforcer.

Version

25.0.5

Expected behavior

When a HTTP request is denied, no additional HTTP request to some "phantom resource" is dispatched.

Actual behavior

With the predefined resources in the sample quickstart realm, this request to /error gets granted. Still it's unclear why this happens.

If user managed access is turned on in rest-authz-resource-server by adding an empty JSON object

{
  "realm": "quickstart",
  "auth-server-url": "http://localhost:8180",
  "resource": "authz-servlet",
  "credentials": {
    "secret": "secret"
  },
  "user-managed-access": {}
}

to policy-enforcer.json, logically, the first request to some valid resource like http://localhost:8080/protected/premium gets denied with a 401 error code and the permission ticket in the WWW-Authenticate header of the response. However, this "phantom request" to /error gets activated again, which in turn provokes the issuance of a permission ticket from Keycloak, and the that "phantom request" itself gets denied.

The problem with this behaviour is that from the point of view of a HTTP client (I used curl and Insomnia during my experiments) only the latter permission ticket associated with the "phantom request" is received. In terms of the example of rest-authz-resource-server, even if I request http://localhost:8080/protected/premium, I get a permission ticket back caused by /error/ which is covered by the /* URI path of resources as if I had requested http://localhost:8080.

How to Reproduce?

For below steps I did NOT activate UMA as described above - NO empty JSON object "user-managed-access" in policy-enforcer.json.

• set the log level to DEBUG for org.keycloak.authorization.client as well as org.keycloak.adapters.authorization in application.yml

logging:
  level:
    root: INFO
    org.keycloak.authorization.client: DEBUG
    org.keycloak.adapters.authorization: DEBUG

• start the rest-authz-resource-server with mvn spring-boot:run
• as described in the README, get an access token on behalf of alice
• with that access token request access to http://localhost:8080/protected/premium
curl http://localhost:8080/protected/premium -H "Authorization: Bearer "$access_token

As expected this request is denied, but if you study the debug logs of PolicyEnforcer, you see how the actual request to /protected/premium and then /error are processed.

...
2024-09-20T13:52:33.616+02:00 DEBUG 264648 --- [nio-8080-exec-1] o.k.a.authorization.PolicyEnforcer       : Policy enforcement result for path [/protected/premium] is : DENIED
2024-09-20T13:52:33.616+02:00 DEBUG 264648 --- [nio-8080-exec-1] o.k.a.authorization.PolicyEnforcer       : Returning authorization context with permissions:
2024-09-20T13:52:33.616+02:00 DEBUG 264648 --- [nio-8080-exec-1] o.k.a.a.i.j.ServletPolicyEnforcerFilter  : Unauthorized request to path [/protected/premium], aborting the filter chain

>>> from here it gets weird

2024-09-20T13:52:33.618+02:00 DEBUG 264648 --- [nio-8080-exec-1] o.k.a.authorization.PolicyEnforcer       : Policy enforcement is enabled. Enforcing policy decisions for path [/error].
2024-09-20T13:52:33.619+02:00 DEBUG 264648 --- [nio-8080-exec-1] o.k.a.authorization.PolicyEnforcer       : Checking permissions for path [/error] with config [PathConfig{name='Protected Resource', type='http://servlet-authz/protected/resource', path='/*', scopes=[urn:servlet-authz:protected:resource:access], id='e51c5b3c-e1b3-4892-8157-023eb1ee121a', enforcerMode='ENFORCING'}].

...

2024-09-20T13:52:33.630+02:00 DEBUG 264648 --- [nio-8080-exec-1] o.k.a.authorization.PolicyEnforcer       : Policy enforcement result for path [/error] is : GRANTED
2024-09-20T13:52:33.630+02:00 DEBUG 264648 --- [nio-8080-exec-1] o.k.a.authorization.PolicyEnforcer       : Returning authorization context with permissions:
2024-09-20T13:52:33.630+02:00 DEBUG 264648 --- [nio-8080-exec-1] o.k.a.authorization.PolicyEnforcer       : Permission {id=e51c5b3c-e1b3-4892-8157-023eb1ee121a, name=Protected Resource, scopes=[urn:servlet-authz:protected:resource:access]}
2024-09-20T13:52:33.630+02:00 DEBUG 264648 --- [nio-8080-exec-1] o.k.a.a.i.j.ServletPolicyEnforcerFilter  : Request authorized, continuing the filter chain

Anything else?

As a consequence, there can be situations where I get no or an incorrect RPT when turning in the permission ticket at the token endpoint, so that a resource access is not granted although it should have been.

This somehow renders the policy enforcer implementation useless in case of UMA turned on.