search

p2-inc / keycloak-events

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

Admin events not available in Webhooks? #6

Closed nefarius closed 1 year ago

nefarius commented 1 year ago

Ahoy!

I followed the example on the README and successfully get notified if VERIFY_EMAIL, SEND_VERIFY_EMAIL, or REGISTER has happened. But I'm also interested in Admin events like REALM_ROLE_MAPPING | CREATE , is this supported?

Thanks

xgp commented 1 year ago

Yes. You may have noticed that the format of the "event" is similar but not exactly the same as the standard Keycloak events. The type field is prefixed with access., admin., system., and you can use these to subscribe to each of these event types. Some examples of types you can use when setting up your webhooks:

There's some documentation started under the "Audit Logs" section of our product documentation https://phasetwo.io/docs/audit-logs/ that might be helpful context.

nefarius commented 1 year ago

I am subscribed to everything using the wildcard. I turned DEBUG logging back on and captured two exceptions:

2022-11-16 18:50:08,246 DEBUG [org.hibernate.event.internal.AbstractSaveEventListener] (executor-thread-1) Generated identifier: f64e339e-fa6d-44c0-a883-04140d6720ac, using strategy: org.hibernate.id.Assigned
2022-11-16 18:50:08,247 DEBUG [io.phasetwo.keycloak.events.MultiEventListenerProvider] (executor-thread-1) onEvent CREATE REALM_ROLE_MAPPING users/314262cc-4e93-4df2-b30e-66427b0fb503/role-mappings/realm
2022-11-16 18:50:08,248 DEBUG [org.jboss.aerogear.keycloak.metrics.MetricsEventListener] (executor-thread-1) Received admin event of type CREATE (REALM_ROLE_MAPPING) in realm 4815181e-2c88-4491-a630-840f7813ce0b
2022-11-16 18:50:08,249 DEBUG [io.phasetwo.keycloak.events.MultiEventListenerProvider] (executor-thread-1) onEvent CREATE REALM_ROLE_MAPPING users/314262cc-4e93-4df2-b30e-66427b0fb503/role-mappings/realm
2022-11-16 18:50:08,249 DEBUG [io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider] (executor-thread-1) onEvent CREATE REALM_ROLE_MAPPING users/314262cc-4e93-4df2-b30e-66427b0fb503/role-mappings/realm
2022-11-16 18:50:08,254 DEBUG [io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider] (executor-thread-1) couldn't get sessionId: java.lang.NullPointerException
      at io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider.completeExtendedAuthDetails(WebhookSenderEventListenerProvider.java:196)
      at io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider.completeAdminEventAttributes(WebhookSenderEventListenerProvider.java:187)
      at io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider.onEvent(WebhookSenderEventListenerProvider.java:71)
      at org.keycloak.services.resources.admin.AdminEventBuilder.send(AdminEventBuilder.java:251)
      at org.keycloak.services.resources.admin.AdminEventBuilder.success(AdminEventBuilder.java:233)
      at org.keycloak.services.resources.admin.RoleMapperResource.addRealmRoleMappings(RoleMapperResource.java:234)
      at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
      at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      at java.base/java.lang.reflect.Method.invoke(Method.java:566)
      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: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:1212)
      at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
      at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
      at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:67)
      at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:55)
      at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1212)
      at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
      at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
      at io.quarkus.vertx.http.runtime.VertxHttpRecorder$5.handle(VertxHttpRecorder.java:380)
      at io.quarkus.vertx.http.runtime.VertxHttpRecorder$5.handle(VertxHttpRecorder.java:358)
      at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1212)
      at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
      at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
      at org.keycloak.quarkus.runtime.integration.web.QuarkusRequestFilter.lambda$createBlockingHandler$1(QuarkusRequestFilter.java:90)
      at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:159)
      at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100)
      at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$1(ContextImpl.java:157)
      at io.quarkus.vertx.core.runtime.VertxCoreRecorder$13.runWith(VertxCoreRecorder.java:545)
      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:829)

2022-11-16 18:50:08,255 DEBUG [io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider] (executor-thread-1) couldn't get realmId: java.lang.NullPointerException
      at io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider.completeExtendedAuthDetails(WebhookSenderEventListenerProvider.java:202)
      at io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider.completeAdminEventAttributes(WebhookSenderEventListenerProvider.java:187)
      at io.phasetwo.keycloak.events.WebhookSenderEventListenerProvider.onEvent(WebhookSenderEventListenerProvider.java:71)
      at org.keycloak.services.resources.admin.AdminEventBuilder.send(AdminEventBuilder.java:251)
      at org.keycloak.services.resources.admin.AdminEventBuilder.success(AdminEventBuilder.java:233)
      at org.keycloak.services.resources.admin.RoleMapperResource.addRealmRoleMappings(RoleMapperResource.java:234)
      at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
      at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      at java.base/java.lang.reflect.Method.invoke(Method.java:566)
      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: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:1212)
      at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
      at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
      at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:67)
      at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:55)
      at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1212)
      at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
      at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
      at io.quarkus.vertx.http.runtime.VertxHttpRecorder$5.handle(VertxHttpRecorder.java:380)
      at io.quarkus.vertx.http.runtime.VertxHttpRecorder$5.handle(VertxHttpRecorder.java:358)
      at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1212)
      at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:163)
      at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:141)
      at org.keycloak.quarkus.runtime.integration.web.QuarkusRequestFilter.lambda$createBlockingHandler$1(QuarkusRequestFilter.java:90)
      at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:159)
      at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100)
      at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$1(ContextImpl.java:157)
      at io.quarkus.vertx.core.runtime.VertxCoreRecorder$13.runWith(VertxCoreRecorder.java:545)
      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:829)

2022-11-16 18:50:08,256 DEBUG [org.keycloak.transaction.JtaTransactionWrapper] (executor-thread-1) JtaTransactionWrapper  commit
2022-11-16 18:50:08,257 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (executor-thread-1) Processing flush-time cascades
2022-11-16 18:50:08,257 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (executor-thread-1) Dirty checking collections

How to solve seems to be out of my league for the moment it appears 🤔

xgp commented 1 year ago

Those are debug logged exceptions that get ignored. Some events will neither have a sessionId nor a realmId, so it's just indicating (for debugging purposes) that it can't load them. Because the exception isn't thrown, it shouldn't stop the event from being sent to the webhook.

There was a recent bug that threw some of the validation exceptions. Are you building from main or using one of the released jars?

nefarius commented 1 year ago

There was a recent bug that threw some of the validation exceptions. Are you building from main or using one of the released jars?

I built it from main just a couple hours ago. It produced a keycloak-events-0.7-SNAPSHOT.jar

Using it with quay.io/keycloak/keycloak:19.0.2

xgp commented 1 year ago

Do you see either of these in your debug logs for the events that are not emitted? Error converting and scheduling event Checking webhook enabled for

nefarius commented 1 year ago

Neither I'm afraid.

xgp commented 1 year ago

Thanks for all the context. I'll spend some time trying to reproduce.

nefarius commented 1 year ago

This is my Dockerfile btw., nothing special:

FROM quay.io/keycloak/keycloak:19.0.2 as builder

ENV TZ=Europe/Vienna
ENV KC_HEALTH_ENABLED=true
ENV KC_METRICS_ENABLED=true
ENV KC_FEATURES=token-exchange
ENV KC_DB=postgres

# https://github.com/aerogear/keycloak-metrics-spi
RUN curl -sL https://github.com/aerogear/keycloak-metrics-spi/releases/download/2.5.3/keycloak-metrics-spi-2.5.3.jar -o /opt/keycloak/providers/keycloak-metrics-spi-2.5.3.jar
# https://github.com/p2-inc/keycloak-events
COPY ./keycloak-events-0.7-SNAPSHOT.jar /opt/keycloak/providers/keycloak-events-0.7-SNAPSHOT.jar

RUN /opt/keycloak/bin/kc.sh build --features=admin-fine-grained-authz

FROM quay.io/keycloak/keycloak:19.0.2
COPY --from=builder /opt/keycloak/ /opt/keycloak/
WORKDIR /opt/keycloak

ENTRYPOINT ["/opt/keycloak/bin/kc.sh", "start", "--proxy=edge", "--optimized", "--log-level=DEBUG"]

Relevant docker-compose.yml snippet:

  keycloak:
    image: keycloak:19.0
    container_name: keycloak
    restart: unless-stopped
    environment:
      KC_DB_URL: jdbc:postgresql://postgres:5432/keycloak
      KC_DB_USERNAME: keycloak
      KC_DB_PASSWORD: 1111
      KEYCLOAK_ADMIN: admin
      KEYCLOAK_ADMIN_PASSWORD: 1111
      KC_HOSTNAME_URL: https://devserver/
      KC_HOSTNAME_ADMIN_URL: https://devserver/
xgp commented 1 year ago

Thanks. Can you also tell me how you are creating the webhook? The request payload should be sufficient.

nefarius commented 1 year ago

Like so (it returned success):

{
  "enabled": "true",
  "url": "http://docker-webserver:5010/api/webhooks/77fd09e5-6532-4e6f-8ce4-72023050f5fc",
  "secret": "3eAuFbcA",
  "eventTypes": [
    "*"
  ]
}
xgp commented 1 year ago

I ran through that full use case, using a service account and that webhook (with a different URL) and I got all of the events. I did several admin changes (including a CREATE->REALM_ROLE_MAPPING, as you have in the exception) and nothing failed.

Maybe it's how you're triggering the events? Is it via activity in the admin console? Or the admin API?

nefarius commented 1 year ago

Could it be a config problem? Right now I've added my service user and client to the master realm, the events I wanna observe will come mainly from a different realm. I assumed this was correct since the user registration fired the events for that other realm.

Edit: changes in the master realm also won't fire admin events.

nefarius commented 1 year ago

Maybe it's how you're triggering the events? Is it via activity in the admin console? Or the admin API?

Am only using the integrated Admin Web UI.

xgp commented 1 year ago

You have to add the webhook for the realm you want the events from.

On Wed, Nov 16, 2022, at 9:19 PM, Benjamin Höglinger-Stelzer wrote:

Could it be a config problem? Right now I've added my service user and client to the master realm, the events I wanna observe will come mainly from a different realm. I assumed this was correct since the user registration fired the events for that other realm.

— Reply to this email directly, view it on GitHub https://github.com/p2-inc/keycloak-events/issues/6#issuecomment-1317616305, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAB3UHKOJHY2IMWL23TP7NLWIU6UHANCNFSM6AAAAAASCRJTOY. You are receiving this because you were assigned.Message ID: @.***>

nefarius commented 1 year ago

You have to add the webhook for the realm you want the events from.

OK then that is correct, the webhook was created for that "production" realm, not master.

Response

[
    {
        "id": "6e5a24c4-118b-4bad-bf26-f8e836205080",
        "enabled": true,
        "url": "http://docker-webserver:5010/api/webhooks/77fd09e5-6532-4e6f-8ce4-72023050f5fc",
        "createdBy": "efad3d71-e455-4c8b-a920-6926d9a380b6",
        "createdAt": 1668622533549,
        "realm": "CENSORED",
        "eventTypes": [
            "*"
        ]
    }
]
nefarius commented 1 year ago

Goodness, I figured it out, it all works! I was editing users in the other realm but being logged in with a master realm admin! I've added a 2nd webhook to master and the events are there. Now it's obvious, the event is triggered for the realm the performing users is a member of!

Pardon the noise, it appears everything is working as intended 😬

xgp commented 1 year ago

Glad you got it working. Using the master realm often leads to weird, idiopathic outcomes. I have noticed, in the Keycloak code, and when writing extensions, that there is a lot of conditional handling for actions by users logged into the master realm. In practice, I try to never do it, and always create an admin user and/or service account in the target realm, and never use the master realm admin for anything but creating new realms.