p2-inc / keycloak-events

Useful Keycloak event listener implementations and utilities.
https://phasetwo.io
Other
168 stars 35 forks source link

Uncaught server error caused by null pointer exception #28

Closed NikosKoukoumelis closed 1 year ago

NikosKoukoumelis commented 1 year ago

Hello,

After upgrading keycloak from version 20.0.5 to 21.1.1 and keycloak-events jar file from version 0.8 to 0.17 we started receiving errors from ext-event-http event listener.

The exception message we get is the following: Uncaught server error: Cannot invoke "org.keycloak.models.RealmModel.getName()" because the return value of "org.keycloak.models.KeycloakContext.getRealm()" is null

and the stack trace is the following:

{
  "method": "getConfigurations",
  "line": 16,
  "class": "io.phasetwo.keycloak.config.ConfigurationAware"
},
{
  "method": "create",
  "line": 22,
  "class": "io.phasetwo.keycloak.events.MultiEventListenerProviderFactory"
},
{
  "method": "create",
  "line": 13,
  "class": "io.phasetwo.keycloak.events.MultiEventListenerProviderFactory"
},
{
  "method": "getProvider",
  "line": 288,
  "class": "org.keycloak.services.DefaultKeycloakSession"
},
{
  "method": "lambda$getEventListeners$0",
  "line": 77,
  "class": "org.keycloak.events.EventBuilder"
},
{
  "method": "accept",
  "line": 197,
  "class": "java.util.stream.ReferencePipeline$3$1"
},
{
  "method": "forEachRemaining",
  "line": 1707,
  "class": "java.util.HashMap$KeySpliterator"
},
{
  "method": "copyInto",
  "line": 509,
  "class": "java.util.stream.AbstractPipeline"
},
{
  "method": "wrapAndCopyInto",
  "line": 499,
  "class": "java.util.stream.AbstractPipeline"
},
{
  "method": "evaluateSequential",
  "line": 921,
  "class": "java.util.stream.ReduceOps$ReduceOp"
},
{
  "method": "evaluate",
  "line": 234,
  "class": "java.util.stream.AbstractPipeline"
},
{
  "method": "collect",
  "line": 682,
  "class": "java.util.stream.ReferencePipeline"
},
{
  "method": "getEventListeners",
  "line": 86,
  "class": "org.keycloak.events.EventBuilder"
},
{
  "method": "lambda$send$1",
  "line": 239,
  "class": "org.keycloak.events.EventBuilder"
},
{
  "method": "lambda$runJobInTransaction$1",
  "line": 256,
  "class": "org.keycloak.models.utils.KeycloakModelUtils"
},
{
  "method": "runJobInTransactionWithResult",
  "line": 269,
  "class": "org.keycloak.models.utils.KeycloakModelUtils"
},
{
  "method": "runJobInTransaction",
  "line": 255,
  "class": "org.keycloak.models.utils.KeycloakModelUtils"
},
{
  "method": "send",
  "line": 237,
  "class": "org.keycloak.events.EventBuilder"
},
{
  "method": "error",
  "line": 224,
  "class": "org.keycloak.events.EventBuilder"
},
{
  "method": "isActionActive",
  "line": 350,
  "class": "org.keycloak.services.resources.SessionCodeChecks"
},
{
  "method": "verifyActiveAndValidAction",
  "line": 327,
  "class": "org.keycloak.services.resources.SessionCodeChecks"
},
{
  "method": "authenticateInternal",
  "line": 277,
  "class": "org.keycloak.services.resources.LoginActionsService"
},
{
  "method": "access$100",
  "line": 111,
  "class": "org.keycloak.services.resources.LoginActionsService"
},
{
  "method": "runInternal",
  "line": 266,
  "class": "org.keycloak.services.resources.LoginActionsService$1"
},
{
  "method": "run",
  "line": 67,
  "class": "org.keycloak.common.util.ResponseSessionTask"
},
{
  "method": "run",
  "line": 44,
  "class": "org.keycloak.common.util.ResponseSessionTask"
},
{
  "method": "runJobInRetriableTransaction",
  "line": 299,
  "class": "org.keycloak.models.utils.KeycloakModelUtils"
},
{
  "method": "authenticate",
  "line": 259,
  "class": "org.keycloak.services.resources.LoginActionsService"
},
{
  "method": "authenticateForm",
  "line": 351,
  "class": "org.keycloak.services.resources.LoginActionsService"
},
{
  "method": "invoke0",
  "class": "jdk.internal.reflect.NativeMethodAccessorImpl"
},
{
  "method": "invoke",
  "line": 77,
  "class": "jdk.internal.reflect.NativeMethodAccessorImpl"
},
{
  "method": "invoke",
  "line": 43,
  "class": "jdk.internal.reflect.DelegatingMethodAccessorImpl"
},
{
  "method": "invoke",
  "line": 568,
  "class": "java.lang.reflect.Method"
},
{
  "method": "invoke",
  "line": 170,
  "class": "org.jboss.resteasy.core.MethodInjectorImpl"
},
{
  "method": "invoke",
  "line": 130,
  "class": "org.jboss.resteasy.core.MethodInjectorImpl"
},
{
  "method": "internalInvokeOnTarget",
  "line": 660,
  "class": "org.jboss.resteasy.core.ResourceMethodInvoker"
},
{
  "method": "invokeOnTargetAfterFilter",
  "line": 524,
  "class": "org.jboss.resteasy.core.ResourceMethodInvoker"
},
{
  "method": "lambda$invokeOnTarget$2",
  "line": 474,
  "class": "org.jboss.resteasy.core.ResourceMethodInvoker"
},
{
  "method": "filter",
  "line": 364,
  "class": "org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext"
},
{
  "method": "invokeOnTarget",
  "line": 476,
  "class": "org.jboss.resteasy.core.ResourceMethodInvoker"
},
{
  "method": "invoke",
  "line": 434,
  "class": "org.jboss.resteasy.core.ResourceMethodInvoker"
},
{
  "method": "invokeOnTargetObject",
  "line": 192,
  "class": "org.jboss.resteasy.core.ResourceLocatorInvoker"
},
{
  "method": "invoke",
  "line": 141,
  "class": "org.jboss.resteasy.core.ResourceLocatorInvoker"
},
{
  "method": "invoke",
  "line": 32,
  "class": "org.jboss.resteasy.core.ResourceLocatorInvoker"
},
{
  "method": "invoke",
  "line": 492,
  "class": "org.jboss.resteasy.core.SynchronousDispatcher"
},
{
  "method": "lambda$invoke$4",
  "line": 261,
  "class": "org.jboss.resteasy.core.SynchronousDispatcher"
},
{
  "method": "lambda$preprocess$0",
  "line": 161,
  "class": "org.jboss.resteasy.core.SynchronousDispatcher"
},
{
  "method": "filter",
  "line": 364,
  "class": "org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext"
},
{
  "method": "preprocess",
  "line": 164,
  "class": "org.jboss.resteasy.core.SynchronousDispatcher"
},
{
  "method": "invoke",
  "line": 247,
  "class": "org.jboss.resteasy.core.SynchronousDispatcher"
},
{
  "method": "service",
  "line": 73,
  "class": "io.quarkus.resteasy.runtime.standalone.RequestDispatcher"
},
{
  "method": "dispatch",
  "line": 151,
  "class": "io.quarkus.resteasy.runtime.standalone.VertxRequestHandler"
},
{
  "method": "handle",
  "line": 82,
  "class": "io.quarkus.resteasy.runtime.standalone.VertxRequestHandler"
},
{
  "method": "handle",
  "line": 42,
  "class": "io.quarkus.resteasy.runtime.standalone.VertxRequestHandler"
},
{
  "method": "handleContext",
  "line": 1284,
  "class": "io.vertx.ext.web.impl.RouteState"
},
{
  "method": "iterateNext",
  "line": 173,
  "class": "io.vertx.ext.web.impl.RoutingContextImplBase"
},
{
  "method": "next",
  "line": 200,
  "class": "io.vertx.ext.web.impl.RoutingContextWrapper"
},
{
  "method": "handle",
  "line": 84,
  "class": "io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2"
},
{
  "method": "handle",
  "line": 71,
  "class": "io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2"
},
{
  "method": "handleContext",
  "line": 1284,
  "class": "io.vertx.ext.web.impl.RouteState"
},
{
  "method": "iterateNext",
  "line": 173,
  "class": "io.vertx.ext.web.impl.RoutingContextImplBase"
},
{
  "method": "next",
  "line": 200,
  "class": "io.vertx.ext.web.impl.RoutingContextWrapper"
},
{
  "method": "handle",
  "line": 430,
  "class": "io.quarkus.vertx.http.runtime.VertxHttpRecorder$6"
},
{
  "method": "handle",
  "line": 408,
  "class": "io.quarkus.vertx.http.runtime.VertxHttpRecorder$6"
},
{
  "method": "handleContext",
  "line": 1284,
  "class": "io.vertx.ext.web.impl.RouteState"
},
{
  "method": "iterateNext",
  "line": 173,
  "class": "io.vertx.ext.web.impl.RoutingContextImplBase"
},
{
  "method": "next",
  "line": 200,
  "class": "io.vertx.ext.web.impl.RoutingContextWrapper"
},
{
  "method": "lambda$createBlockingHandler$0",
  "line": 82,
  "class": "org.keycloak.quarkus.runtime.integration.web.QuarkusRequestFilter"
},
{
  "method": "runWith",
  "line": 576,
  "class": "io.quarkus.vertx.core.runtime.VertxCoreRecorder$14"
},
{
  "method": "run",
  "line": 2449,
  "class": "org.jboss.threads.EnhancedQueueExecutor$Task"
},
{
  "method": "run",
  "line": 1478,
  "class": "org.jboss.threads.EnhancedQueueExecutor$ThreadBody"
},
{
  "method": "run",
  "line": 29,
  "class": "org.jboss.threads.DelegatingRunnable"
},
{
  "method": "run",
  "line": 29,
  "class": "org.jboss.threads.ThreadLocalResettingRunnable"
},
{
  "method": "run",
  "line": 30,
  "class": "io.netty.util.concurrent.FastThreadLocalRunnable"
},
{
  "method": "run",
  "line": 833,
  "class": "java.lang.Thread"
}

Can you assist us to overcome this if it is not a bug?

Thanks in advance.

xgp commented 1 year ago

Sorry, I can't read that stack trace.

NikosKoukoumelis commented 1 year ago

Thanks for your immediate response, I have edited my original comment. Is it more readable now?

xgp commented 1 year ago

Yes. Thanks. There are some inconsistencies with how the KeycloakContext is populated based on how the event gets invoked. We had another bug similar to this, and we thought we fixed all cases. I’ll take a look and see if this is one we didn’t anticipate.

Can you provide some more details? Is it throwing this error on all events, or just certain types?

NikosKoukoumelis commented 1 year ago

We are not sure which are the types of events that cause the error but we know that LOGIN_ERROR and CLIENT_LOGIN_ERROR produce it.

xgp commented 1 year ago

Sorry, would you mind turning off JSON logging or whatever you're running and pasting a full stack trace of what you're seeing? I'm not able to reproduce, and won't be able to figure out where it's happening without a real stack trace.

xgp commented 1 year ago

Also, paste the config from the realm attribute you're using (remove any sensitive information).

xgp commented 1 year ago

Looks like it is related to this in Keycloak https://github.com/keycloak/keycloak/issues/20105

If the KeycloakContext realm isn't properly getting set, the ConfigurationAware lookup method will throw this exception. Should be fixed in KC 22.

xgp commented 1 year ago

Not sure if any of these will work for you, because I haven't been able to recreate the problem, but if you can try this branch, please do and let me know if it works: https://github.com/p2-inc/keycloak-events/tree/xgp/get-realm-context-bug

NikosKoukoumelis commented 1 year ago

We tried out the branch and we kept getting the error, I am attaching a file with the full stack trace. I am coming back shortly with the realm attribute config. log.txt

NikosKoukoumelis commented 1 year ago

Here is the realm attribute config realm_attribute_202307101613.txt

Thanks for you help.

xgp commented 1 year ago

@NikosKoukoumelis Thanks for the clean stack trace. I was able to reproduce, and it's because of the bug https://github.com/keycloak/keycloak/issues/20105 in Keycloak that was introduced in version 21.1.x. There isn't a workaround in this case, because there is no other way for this code to get the Realm. The Keycloak maintainers have indicated that the fix will be in version 22.

xgp commented 1 year ago

@NikosKoukoumelis Keycloak 22.0.0 is out today. It includes a fix for https://github.com/keycloak/keycloak/issues/20105 which should fix this issue. I will test this against the upgraded version in the next few days, but you might want to try that version now if you are in a hurry.

NikosKoukoumelis commented 1 year ago

@xgp We updated keycloak and got the latest release of keycloak-events, no error is thrown now. Thanks for your help and guidance!