Keycloak PolicyEnforcer logs "Could not lazy load resource" for public entpoints

joggeli34 commented 3 years ago

Describe the bug

When using keycloak-authorization, the public endpoints (e.g. /q/health/live) are logging following exception when keycloak is not reachable (due to restart or something else).

2021-07-19 14:05:13,557 ERROR [org.key.ada.aut.PolicyEnforcer] (executor-thread-4) Could not lazy load resource with path [/q/health/live] from server: java.lang.RuntimeException: Could not find resource
    at org.keycloak.authorization.client.util.Throwables.retryAndWrapExceptionIfNecessary(Throwables.java:91)
    at org.keycloak.authorization.client.resource.ProtectedResource.find(ProtectedResource.java:232)
    at org.keycloak.authorization.client.resource.ProtectedResource.findByMatchingUri(ProtectedResource.java:291)
    at org.keycloak.adapters.authorization.PolicyEnforcer$PathConfigMatcher.matches(PolicyEnforcer.java:272)
    at io.quarkus.keycloak.pep.runtime.KeycloakPolicyEnforcerAuthorizer.apply(KeycloakPolicyEnforcerAuthorizer.java:47)
    at io.quarkus.keycloak.pep.runtime.KeycloakPolicyEnforcerAuthorizer.apply(KeycloakPolicyEnforcerAuthorizer.java:28)
    at io.quarkus.vertx.http.runtime.security.HttpAuthorizer$1$1$1.run(HttpAuthorizer.java:72)
    at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:481)
    at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2442)
    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1476)
    at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
    at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
    at java.base/java.lang.Thread.run(Unknown Source)
Caused by: org.keycloak.authorization.client.util.HttpResponseException: Unexpected response from server: 503 / Service Temporarily Unavailable / Response from server: <html>

The api call stays responsive, even if this error is logged. So it's more a problem about polluting the log and not about the functionality.

But I assumed that keycloak is not called if the endpoint is public anyway, which probably reduces the load on the keycloak-server as the liveness check is called often in a kubernetes-deployment.

Expected behavior

No error is logged for public endpoints as I assumed that keycloak must not be called if the endpoint is public anyway.

Actual behavior

The exception is logged, but the endpoint is reachable with out a problem.

How to Reproduce?

Create a project with keycloak-authorization and health

only policy-enforcer spesific settings in application.properties

quarkus.keycloak.policy-enforcer.enable=true
quarkus.keycloak.policy-enforcer.enforcement-mode=enforcing

Start the application with a running keycloak
Terminate the keycloak
call /q/health/live

Output of `uname -a` or `ver`

No response

Output of `java -version`

No response

GraalVM version (if different from Java)

No response

Quarkus version or git rev

2.0.2.Final

Build tool (ie. output of `mvnw --version` or `gradlew --version`)

No response

Additional information

No response

quarkus-bot[bot] commented 3 years ago

/cc @geoand

geoand commented 3 years ago

cc @sberyozkin

sberyozkin commented 3 years ago

@joggeli34 If quarkus.keycloak.policy-enforcer.enforcement-mode=enforcing then an attempt is made to check the remote configuration - I think you need to disable a policy check for this path to avoid the remote calls, can you try it please ?

CC @pedroigor

joggeli34 commented 3 years ago

The same happens also when changing the configuraiton to:

quarkus.keycloak.policy-enforcer.enable=true
quarkus.keycloak.policy-enforcer.enforcement-mode=enforcing
quarkus.keycloak.policy-enforcer.paths.q.path=/q/*
quarkus.keycloak.policy-enforcer.paths.q.enforcement-mode=disabled

joggeli34 commented 3 years ago

When using follwing configuration (as all my paths are under /api/ anyway), the authentication is disabled "/api/" too, but I was expecting that it would be enabled for all the paths under /api/*

quarkus.keycloak.policy-enforcer.enable=true
quarkus.keycloak.policy-enforcer.enforcement-mode=disabled
quarkus.keycloak.policy-enforcer.paths.api.path=/api/*
quarkus.keycloak.policy-enforcer.paths.api.enforcement-mode=enforcing

sberyozkin commented 3 years ago

@joggeli34 Policy enforcer matching code might not be able to handle wildcards when it comes to nested paths, so perhaps it should be

quarkus.keycloak.policy-enforcer.paths.q.path=/q/health/*
quarkus.keycloak.policy-enforcer.paths.q.enforcement-mode=disabled

joggeli34 commented 3 years ago

After some debugging, I found out, that the matcher correctly matches /q/* aswell as /q/health/*.

But the path is always checked with keycloak if it has a wildcard. But it also always checks invalidated path, and the path gets always invalidated after some time even when using the the full path /q/health/live.

Here the code from the PolicyEnforcer which does the check (line 270)

            if (enforcerConfig.getLazyLoadPaths() || enforcerConfig.getPathCacheConfig() != null) {
                if ((pathConfig == null || pathConfig.isInvalidated() || pathConfig.getPath().contains("*"))) {
                    try {
                        List<ResourceRepresentation> matchingResources = authzClient.protection().resource().findByMatchingUri(targetUri);
                        if (matchingResources.isEmpty()) {
                            // if this config is invalidated (e.g.: due to cache expiration) we remove and return null
                            if (pathConfig != null && pathConfig.isInvalidated()) {
                                paths.remove(targetUri);
                                return null;
                            }
                        } else {

After it was invalidated, it even get removed from the path and is then handled as if it was never defined. So I can't see a possibility currently to not check public paths against keycloak on each call.

joggeli34 commented 3 years ago

When adding:

quarkus.keycloak.policy-enforcer.paths.q.name=disabled

with the corresponding resource in keycloak, the pathConfig gets marked as static and is then not invalidated anymore. Would it be a possibility to mark all disabled-paths as static directly?

sberyozkin commented 3 years ago

@joggeli34 It might be possible to update the recorder to keep a local path to enforcement mode configuration available outside of Keycloak PolicyEnforcer code, per every tenant, so return not only PolicyEnforcerConfig but also a pair of path + mode from here. Then preserve it here - ex, instead of using PolicyEnforcer as a default and tenant values, use PolicyEnforcerProvider which would hold PolicyEnforcer and that pair of path/mode. Finally, add this local path/mode check above this check which may cause a remote call. If a user has disabled a check for a given path then there is no need to do any further checks, allow the access and return immediately.

The same check should also be done here - if it is a proactive authentication then the token/security identity will be available even when accessing a public resource

I can have a look later - but if you could consider creating a PR then it would accelerate it thanks

sberyozkin commented 3 years ago

@joggeli34 That said, may be we should check with Pedro @pedroigor first - perhaps some configuration is also possible

michalvavrik commented 1 year ago

perhaps some configuration is also possible

After going through Keycloak PolicyEnforcer and PathMatcher, I don't believe there is. Path check performed by PathConfigMatcher is very complex and it can't avoid remote calls for non-static paths with patterns that are not yet in cache. I'd suggest that we go with a check suggested by @sberyozkin above, however instead of doing full path config match, we only solve this issue for cases when path of disabled enforcement policy ends with asterisk. Then we check disabled enforcement path starts with incoming URI (and we create cache and remember it for each tenant), if so, we do not need further checks.

This won't help with complex patterns and path parameters and suffixes described by https://www.keycloak.org/docs/latest/authorization_services/#_enforcer_overview, but fixes the issue as it only complains about paths ending with wildcards. If there are no objections, I'll try that.

michalvavrik commented 1 year ago

I gave up on contributing to Keycloak the change we need after few months waiting without response. Someone else will need to contribute to Keycloak in order to fix this issue.

quarkusio / quarkus