search

p2-inc / keycloak-events

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

I dont get webhook from user profile change (delete insert update) #33

Closed jaakkom closed 1 year ago

jaakkom commented 1 year ago

Hello, i have set up webhook like this:

{
  "enabled": "true",
  "url": "https://xxxxx.m.pipedream.net",
  "secret": "SECRET",
  "eventTypes": [
    "*"
  ]
}

But i dont get any webhooks from user profile changes. Realm update sends webhook correctly. What am i doing wrong?

xgp commented 1 year ago

@jaakkom Thanks for the message. Couple of questions:

  1. How are you making "user profile changes"? Admin? API? User account console?
  2. Do you also have jboss-logging event listener configured. Do you see those events in the logs?
  3. Did you turn on DEBUG logging and see any exceptions or problems sending the events?
jaakkom commented 1 year ago
  1. Editing user from admin user interface.
  2. Yes, i can see the events in the ui.
  3. No. But realm editing events go through just fine, so i dont think its "sending " problem.
xgp commented 1 year ago

Thanks @jaakkom. Would you mind restarting with log level DEBUG and let me know if you see any warnings or errors in the logs? I have tried to reproduce on this side, but I can see user profile change events.

jaakkom commented 1 year ago

As you can see, event is listed in admin ui. image

I will try with debug mode.

xgp commented 1 year ago

Any update here?

jaakkom commented 1 year ago

This is propably the reason:

2023-09-04 10:51:27,967 DEBUG [io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider] (executor-thread-5) onEvent UPDATE USER users/b19f7e5a-770a-49af-98d4-0a7ded4e5481
2023-09-04 10:51:27,968 DEBUG [io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider] (executor-thread-5) couldn't get sessionId: java.lang.NullPointerException: Cannot invoke "org.keycloak.sessions.AuthenticationSessionModel.getParentSession()" because the return value of "org.keycloak.models.KeycloakContext.getAuthenticationSession()" is null
    at io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider.completeExtendedAuthDetails(WebhookSenderEventListenerProvider.java:194)
    at io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider.completeAdminEventAttributes(WebhookSenderEventListenerProvider.java:185)
    at io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider.onEvent(WebhookSenderEventListenerProvider.java:69)
    at org.keycloak.services.resources.admin.AdminEventBuilder.send(AdminEventBuilder.java:279)
    at org.keycloak.services.resources.admin.AdminEventBuilder.success(AdminEventBuilder.java:261)
    at org.keycloak.services.resources.admin.UserResource.updateUser(UserResource.java:201)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:568)
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:170)
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:130)
    at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:660)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:524)
    at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:474)
    at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:476)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:434)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:192)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:152)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:183)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:152)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:183)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:152)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:183)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:141)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:32)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:492)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:261)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:161)
    at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
    at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:164)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:247)
    at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:73)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:151)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:82)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:42)
    at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
    at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:173)
    at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:140)
    at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:84)
    at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:71)
    at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
    at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:173)
    at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:140)
    at io.quarkus.vertx.http.runtime.VertxHttpRecorder$6.handle(VertxHttpRecorder.java:430)
    at io.quarkus.vertx.http.runtime.VertxHttpRecorder$6.handle(VertxHttpRecorder.java:408)
    at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
    at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:173)
    at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:140)
    at org.keycloak.quarkus.runtime.integration.web.QuarkusRequestFilter.lambda$createBlockingHandler$0(QuarkusRequestFilter.java:82)
    at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:576)
    at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2449)
    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1478)
    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(Thread.java:833)

2023-09-04 10:51:27,970 DEBUG [io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider] (executor-thread-5) couldn't get realmId: java.lang.NullPointerException: Cannot invoke "org.keycloak.sessions.AuthenticationSessionModel.getParentSession()" because the return value of "org.keycloak.models.KeycloakContext.getAuthenticationSession()" is null
    at io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider.completeExtendedAuthDetails(WebhookSenderEventListenerProvider.java:200)
    at io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider.completeAdminEventAttributes(WebhookSenderEventListenerProvider.java:185)
    at io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider.onEvent(WebhookSenderEventListenerProvider.java:69)
    at org.keycloak.services.resources.admin.AdminEventBuilder.send(AdminEventBuilder.java:279)
    at org.keycloak.services.resources.admin.AdminEventBuilder.success(AdminEventBuilder.java:261)
    at org.keycloak.services.resources.admin.UserResource.updateUser(UserResource.java:201)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:568)
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:170)
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:130)
    at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:660)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:524)
    at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:474)
    at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:476)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:434)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:192)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:152)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:183)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:152)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:183)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:152)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:183)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:141)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:32)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:492)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:261)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:161)
    at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
    at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:164)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:247)
    at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:73)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:151)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:82)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:42)
    at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
    at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:173)
    at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:140)
    at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:84)
    at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:71)
    at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
    at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:173)
    at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:140)
    at io.quarkus.vertx.http.runtime.VertxHttpRecorder$6.handle(VertxHttpRecorder.java:430)
    at io.quarkus.vertx.http.runtime.VertxHttpRecorder$6.handle(VertxHttpRecorder.java:408)
    at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
    at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:173)
    at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:140)
    at org.keycloak.quarkus.runtime.integration.web.QuarkusRequestFilter.lambda$createBlockingHandler$0(QuarkusRequestFilter.java:82)
    at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:576)
    at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2449)
    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1478)
    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(Thread.java:833)
xgp commented 1 year ago

Those are just exceptions that get ignored rather than thrown up the stack. Can you send a full log for an entire request?

jaakkom commented 1 year ago

Not sure where it ends, but is this enough?

2023-09-04 10:51:27,967 DEBUG [org.hibernate.event.internal.AbstractSaveEventListener] (executor-thread-5) Generated identifier: ef75eb8f-bf68-4e30-a926-061593bcd2e2, using strategy: org.hibernate.id.Assigned
2023-09-04 10:51:27,967 DEBUG [io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider] (executor-thread-5) onEvent UPDATE USER users/b19f7e5a-770a-49af-98d4-0a7ded4e5481
2023-09-04 10:51:27,968 DEBUG [io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider] (executor-thread-5) couldn't get sessionId: java.lang.NullPointerException: Cannot invoke "org.keycloak.sessions.AuthenticationSessionModel.getParentSession()" because the return value of "org.keycloak.models.KeycloakContext.getAuthenticationSession()" is null
    at io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider.completeExtendedAuthDetails(WebhookSenderEventListenerProvider.java:194)
    at io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider.completeAdminEventAttributes(WebhookSenderEventListenerProvider.java:185)
    at io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider.onEvent(WebhookSenderEventListenerProvider.java:69)
    at org.keycloak.services.resources.admin.AdminEventBuilder.send(AdminEventBuilder.java:279)
    at org.keycloak.services.resources.admin.AdminEventBuilder.success(AdminEventBuilder.java:261)
    at org.keycloak.services.resources.admin.UserResource.updateUser(UserResource.java:201)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:568)
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:170)
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:130)
    at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:660)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:524)
    at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:474)
    at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:476)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:434)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:192)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:152)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:183)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:152)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:183)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:152)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:183)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:141)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:32)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:492)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:261)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:161)
    at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
    at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:164)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:247)
    at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:73)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:151)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:82)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:42)
    at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
    at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:173)
    at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:140)
    at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:84)
    at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:71)
    at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
    at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:173)
    at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:140)
    at io.quarkus.vertx.http.runtime.VertxHttpRecorder$6.handle(VertxHttpRecorder.java:430)
    at io.quarkus.vertx.http.runtime.VertxHttpRecorder$6.handle(VertxHttpRecorder.java:408)
    at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
    at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:173)
    at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:140)
    at org.keycloak.quarkus.runtime.integration.web.QuarkusRequestFilter.lambda$createBlockingHandler$0(QuarkusRequestFilter.java:82)
    at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:576)
    at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2449)
    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1478)
    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(Thread.java:833)

2023-09-04 10:51:27,970 DEBUG [io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider] (executor-thread-5) couldn't get realmId: java.lang.NullPointerException: Cannot invoke "org.keycloak.sessions.AuthenticationSessionModel.getParentSession()" because the return value of "org.keycloak.models.KeycloakContext.getAuthenticationSession()" is null
    at io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider.completeExtendedAuthDetails(WebhookSenderEventListenerProvider.java:200)
    at io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider.completeAdminEventAttributes(WebhookSenderEventListenerProvider.java:185)
    at io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider.onEvent(WebhookSenderEventListenerProvider.java:69)
    at org.keycloak.services.resources.admin.AdminEventBuilder.send(AdminEventBuilder.java:279)
    at org.keycloak.services.resources.admin.AdminEventBuilder.success(AdminEventBuilder.java:261)
    at org.keycloak.services.resources.admin.UserResource.updateUser(UserResource.java:201)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:568)
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:170)
    at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:130)
    at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:660)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:524)
    at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:474)
    at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:476)
    at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:434)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:192)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:152)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:183)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:152)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:183)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:152)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invokeOnTargetObject(ResourceLocatorInvoker.java:183)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:141)
    at org.jboss.resteasy.core.ResourceLocatorInvoker.invoke(ResourceLocatorInvoker.java:32)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:492)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:261)
    at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:161)
    at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:364)
    at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:164)
    at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:247)
    at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:73)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:151)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:82)
    at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.handle(VertxRequestHandler.java:42)
    at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
    at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:173)
    at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:140)
    at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:84)
    at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:71)
    at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
    at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:173)
    at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:140)
    at io.quarkus.vertx.http.runtime.VertxHttpRecorder$6.handle(VertxHttpRecorder.java:430)
    at io.quarkus.vertx.http.runtime.VertxHttpRecorder$6.handle(VertxHttpRecorder.java:408)
    at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
    at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:173)
    at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:140)
    at org.keycloak.quarkus.runtime.integration.web.QuarkusRequestFilter.lambda$createBlockingHandler$0(QuarkusRequestFilter.java:82)
    at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:576)
    at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2449)
    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1478)
    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(Thread.java:833)

2023-09-04 10:51:27,971 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (executor-thread-5) JtaTransactionWrapper  commit
2023-09-04 10:51:27,971 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (executor-thread-5) Processing flush-time cascades
2023-09-04 10:51:27,971 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (executor-thread-5) Dirty checking collections
2023-09-04 10:51:27,971 DEBUG [org.hibernate.engine.internal.Collections] (executor-thread-5) Collection found: [org.keycloak.models.jpa.entities.UserEntity.attributes#b19f7e5a-770a-49af-98d4-0a7ded4e5481], was: [org.keycloak.models.jpa.entities.UserEntity.attributes#b19f7e5a-770a-49af-98d4-0a7ded4e5481] (initialized)
2023-09-04 10:51:27,971 DEBUG [org.hibernate.engine.internal.Collections] (executor-thread-5) Skipping uninitialized bytecode-lazy collection: [org.keycloak.models.jpa.entities.UserEntity.credentials#b19f7e5a-770a-49af-98d4-0a7ded4e5481]
2023-09-04 10:51:27,971 DEBUG [org.hibernate.engine.internal.Collections] (executor-thread-5) Skipping uninitialized bytecode-lazy collection: [org.keycloak.models.jpa.entities.UserEntity.federatedIdentities#b19f7e5a-770a-49af-98d4-0a7ded4e5481]
2023-09-04 10:51:27,971 DEBUG [org.hibernate.engine.internal.Collections] (executor-thread-5) Collection found: [org.keycloak.models.jpa.entities.UserEntity.requiredActions#b19f7e5a-770a-49af-98d4-0a7ded4e5481], was: [org.keycloak.models.jpa.entities.UserEntity.requiredActions#b19f7e5a-770a-49af-98d4-0a7ded4e5481] (initialized)
2023-09-04 10:51:27,971 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (executor-thread-5) Flushed: 1 insertions, 1 updates, 0 deletions to 2 objects
2023-09-04 10:51:27,971 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (executor-thread-5) Flushed: 0 (re)creations, 0 updates, 0 removals to 4 collections
2023-09-04 10:51:27,972 DEBUG [org.hibernate.internal.util.EntityPrinter] (executor-thread-5) Listing entities:
2023-09-04 10:51:27,972 DEBUG [org.hibernate.internal.util.EntityPrinter] (executor-thread-5) org.keycloak.events.jpa.AdminEventEntity{authIpAddress=193.65.84.6, realmId=49e79ae9-10da-4d1e-a031-9940afbb7aee, authRealmId=master, authUserId=d3283d40-2c69-4800-9ba6-92aee6da4c47, authClientId=2b2bfede-0e3a-49eb-b352-03d44e5510f5, resourcePath=users/b19f7e5a-770a-49af-98d4-0a7ded4e5481, operationType=UPDATE, id=ef75eb8f-bf68-4e30-a926-061593bcd2e2, time=1693824687967, error=null, representation={"id":"b19f7e5a-770a-49af-98d4-0a7ded4e5481","createdTimestamp":1693824341932,"username":"testing","enabled":true,"totp":false,"emailVerified":false,"firstName":"jaakko1adfadf","lastName":"","email":"","attributes":{},"disableableCredentialTypes":[],"requiredActions":[],"notBefore":0,"access":{"manageGroupMembership":true,"view":true,"mapRoles":true,"impersonate":true,"manage":true}}, resourceType=USER}
2023-09-04 10:51:27,972 DEBUG [org.hibernate.internal.util.EntityPrinter] (executor-thread-5) org.keycloak.models.jpa.entities.UserEntity{lastName=, federatedIdentities=<uninitialized>, realmId=49e79ae9-10da-4d1e-a031-9940afbb7aee, credentials=<uninitialized>, createdTimestamp=1693824341932, serviceAccountClientLink=null, enabled=true, notBefore=0, emailConstraint=89277479-585d-424f-8c58-d106deedd327, emailVerified=false, firstName=jaakko1adfadf, requiredActions=[], federationLink=null, attributes=[], id=b19f7e5a-770a-49af-98d4-0a7ded4e5481, email=null, username=testing}
2023-09-04 10:51:27,972 DEBUG [org.hibernate.SQL] (executor-thread-5) insert into ADMIN_EVENT_ENTITY (AUTH_CLIENT_ID, IP_ADDRESS, AUTH_REALM_ID, AUTH_USER_ID, ERROR, OPERATION_TYPE, REALM_ID, REPRESENTATION, RESOURCE_PATH, RESOURCE_TYPE, ADMIN_EVENT_TIME, ID) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
2023-09-04 10:51:27,975 DEBUG [org.hibernate.SQL] (executor-thread-5) update USER_ENTITY set CREATED_TIMESTAMP=?, EMAIL=?, EMAIL_CONSTRAINT=?, EMAIL_VERIFIED=?, ENABLED=?, FEDERATION_LINK=?, FIRST_NAME=?, LAST_NAME=?, NOT_BEFORE=?, REALM_ID=?, SERVICE_ACCOUNT_CLIENT_LINK=?, USERNAME=? where ID=?
2023-09-04 10:51:27,977 DEBUG [org.hibernate.engine.transaction.internal.TransactionImpl] (executor-thread-5) On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2023-09-04 10:51:27,978 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (executor-thread-5) Initiating JDBC connection release from beforeTransactionCompletion
2023-09-04 10:51:27,987 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (executor-thread-5) Initiating JDBC connection release from afterTransaction
2023-09-04 10:51:27,987 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (executor-thread-5) JtaTransactionWrapper end
2023-09-04 10:51:27,989 DEBUG [org.keycloak.events] (executor-thread-5) operationType=UPDATE, realmId=master, clientId=2b2bfede-0e3a-49eb-b352-03d44e5510f5, userId=d3283d40-2c69-4800-9ba6-92aee6da4c47, ipAddress=193.65.84.6, resourceType=USER, resourcePath=users/b19f7e5a-770a-49af-98d4-0a7ded4e5481
2023-09-04 10:51:27,989 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (executor-thread-5) new JtaTransactionWrapper
2023-09-04 10:51:27,989 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (executor-thread-5) was existing? false
2023-09-04 10:51:27,989 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (executor-thread-5) `hibernate.connection.provider_disables_autocommit` was enabled.  This setting should only be enabled when you are certain that the Connections given to Hibernate by the ConnectionProvider have auto-commit disabled.  Enabling this setting when the Connections do not have auto-commit disabled will lead to Hibernate executing SQL operations outside of any JDBC/SQL transaction.
2023-09-04 10:51:27,989 DEBUG [org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl] (executor-thread-5) Hibernate RegisteredSynchronization successfully registered with JTA platform
2023-09-04 10:51:27,990 DEBUG [org.hibernate.SQL] (executor-thread-5) select webhookent0_.ID as id1_93_, webhookent0_.ALGORITHM as algorith2_93_, webhookent0_.CREATED_AT as created_3_93_, webhookent0_.CREATED_BY_USER_ID as created_4_93_, webhookent0_.ENABLED as enabled5_93_, webhookent0_.REALM_ID as realm_id6_93_, webhookent0_.SECRET as secret7_93_, webhookent0_.URL as url8_93_ from WEBHOOK webhookent0_ where webhookent0_.REALM_ID=?
2023-09-04 10:51:27,995 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (executor-thread-5) JtaTransactionWrapper  commit
2023-09-04 10:51:27,995 DEBUG [org.hibernate.engine.transaction.internal.TransactionImpl] (executor-thread-5) On TransactionImpl creation, JpaCompliance#isJpaTransactionComplianceEnabled == false
2023-09-04 10:51:27,995 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (executor-thread-5) Initiating JDBC connection release from beforeTransactionCompletion
2023-09-04 10:51:27,999 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (executor-thread-5) Initiating JDBC connection release from afterTransaction
2023-09-04 10:51:28,000 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (executor-thread-5) JtaTransactionWrapper end
2023-09-04 10:51:28,000 DEBUG [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl] (executor-thread-5) HHH000420: Closing un-released batch
2023-09-04 10:51:28,046 DEBUG [io.quarkus.vertx.http.runtime.ForwardedParser] (vert.x-eventloop-thread-1) Recalculated absoluteURI to https://keycloak.ved218.fisplay.cloud/admin/realms/webhook-test/attack-detection/brute-force/users/b19f7e5a-770a-49af-98d4-0a7ded4e5481
2023-09-04 10:51:28,046 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (executor-thread-5) new JtaTransactionWrapper
2023-09-04 10:51:28,046 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (executor-thread-5) was existing? false
2023-09-04 10:51:28,047 DEBUG [io.quarkus.vertx.http.runtime.ForwardedParser] (vert.x-eventloop-thread-3) Recalculated absoluteURI to https://keycloak.ved218.fisplay.cloud/admin/realms/webhook-test
2023-09-04 10:51:28,048 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (executor-thread-4) new JtaTransactionWrapper
2023-09-04 10:51:28,048 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (executor-thread-4) was existing? false
2023-09-04 10:51:28,050 DEBUG [org.keycloak.services.resources.admin.AdminRoot] (executor-thread-5) authenticated admin access for: jaakko.mantila
2023-09-04 10:51:28,050 DEBUG [org.keycloak.services.resources.Cors] (executor-thread-5) Added CORS headers to response
2023-09-04 10:51:28,051 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (executor-thread-5) `hibernate.connection.provider_disables_autocommit` was enabled.  This setting should only be enabled when you are certain that the Connections given to Hibernate by the ConnectionProvider have auto-commit disabled.  Enabling this setting when the Connections do not have auto-commit disabled will lead to Hibernate executing SQL operations outside of any JDBC/SQL transaction.
2023-09-04 10:51:28,051 DEBUG [org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl] (executor-thread-5) Hibernate RegisteredSynchronization successfully registered with JTA platform
2023-09-04 10:51:28,051 DEBUG [io.quarkus.vertx.http.runtime.ForwardedParser] (vert.x-eventloop-thread-0) Recalculated absoluteURI to https://keycloak.ved218.fisplay.cloud/admin/realms/webhook-test/users/b19f7e5a-770a-49af-98d4-0a7ded4e5481
xgp commented 1 year ago

Thanks. It's not getting to the enabled check https://github.com/p2-inc/keycloak-events/blob/main/src/main/java/io/phasetwo/keycloak/events/WebhookSenderEventListenerProvider.java#L122 so I'm thinking it's not even loading the webhook. I'll try to reproduce again with some more logging.

xgp commented 1 year ago

This works fine for me.

Can you verify the webhook setup is in the same realm as the realm where the user is being updated?

jaakkom commented 1 year ago

I have logged in with "master realm" user, and editing other tenantX users, does that affect to selection? Still, some webhooks come through, but not all.

TenantX has webhook activated, but no master realm.

xgp commented 1 year ago

You have a realm (not master), with the ext-event-webhook listener enabled and a webhook configured. You log into the Admin UI with master realm credentials, and switch to the other realm. You then make changes to that realm and "see" realm UPDATE events, but no other events (e.g. Clients, Users, etc.). Is that right?

I think Keycloak is sending realmId == master. This is a weird quirk of Keycloak when logged into the master realm with role admin (or equivalent). This is not an expected use case.

jaakkom commented 1 year ago

This is confirmed reason. Using Master admin login wont trigger webhooks when editing child realms users etc.

I think this is still bug, it should catch all events, but now its not. The way keycloak user does the user edition should not affect to webhooks.

xgp commented 1 year ago

Thanks. Looking forward to your PR!