KEYCLOAK-16801 Improve performance of ClearExpiredEvents background task

This commit is contained in:
mposolda 2021-01-13 08:43:08 +01:00 committed by Marek Posolda
parent b89edabcfc
commit 99a70267d9
9 changed files with 128 additions and 17 deletions

View file

@ -20,6 +20,7 @@ package org.keycloak.events.jpa;
import com.fasterxml.jackson.core.type.TypeReference; import com.fasterxml.jackson.core.type.TypeReference;
import com.fasterxml.jackson.databind.ObjectMapper; import com.fasterxml.jackson.databind.ObjectMapper;
import org.jboss.logging.Logger; import org.jboss.logging.Logger;
import org.keycloak.common.util.Time;
import org.keycloak.events.Event; import org.keycloak.events.Event;
import org.keycloak.events.EventQuery; import org.keycloak.events.EventQuery;
import org.keycloak.events.EventStoreProvider; import org.keycloak.events.EventStoreProvider;
@ -28,10 +29,13 @@ import org.keycloak.events.admin.AdminEvent;
import org.keycloak.events.admin.AdminEventQuery; import org.keycloak.events.admin.AdminEventQuery;
import org.keycloak.events.admin.AuthDetails; import org.keycloak.events.admin.AuthDetails;
import org.keycloak.events.admin.OperationType; import org.keycloak.events.admin.OperationType;
import org.keycloak.models.KeycloakSession;
import org.keycloak.models.utils.KeycloakModelUtils;
import javax.persistence.EntityManager; import javax.persistence.EntityManager;
import java.io.IOException; import java.io.IOException;
import java.util.HashMap; import java.util.HashMap;
import java.util.List;
import java.util.Map; import java.util.Map;
import java.util.UUID; import java.util.UUID;
@ -45,10 +49,12 @@ public class JpaEventStoreProvider implements EventStoreProvider {
}; };
private static final Logger logger = Logger.getLogger(JpaEventStoreProvider.class); private static final Logger logger = Logger.getLogger(JpaEventStoreProvider.class);
private final KeycloakSession session;
private final EntityManager em; private final EntityManager em;
private final int maxDetailLength; private final int maxDetailLength;
public JpaEventStoreProvider(EntityManager em, int maxDetailLength) { public JpaEventStoreProvider(KeycloakSession session, EntityManager em, int maxDetailLength) {
this.session = session;
this.em = em; this.em = em;
this.maxDetailLength = maxDetailLength; this.maxDetailLength = maxDetailLength;
} }
@ -73,6 +79,37 @@ public class JpaEventStoreProvider implements EventStoreProvider {
em.createQuery("delete from EventEntity where realmId = :realmId and time < :time").setParameter("realmId", realmId).setParameter("time", olderThan).executeUpdate(); em.createQuery("delete from EventEntity where realmId = :realmId and time < :time").setParameter("realmId", realmId).setParameter("time", olderThan).executeUpdate();
} }
@Override
public void clearExpiredEvents() {
// By default, realm provider is always "jpa", so we can optimize and delete all events in single SQL, assuming that realms are saved in the DB as well.
// Fallback to model API just with different realm provider than "jpa" (This is never the case in standard Keycloak installations)
int numDeleted = 0;
long currentTimeMillis = Time.currentTimeMillis();
if (KeycloakModelUtils.isRealmProviderJpa(session)) {
// Group realms by expiration times. This will be effective if different realms have same/similar event expiration times, which will probably be the case in most environments
List<Long> eventExpirations = em.createQuery("select distinct realm.eventsExpiration from RealmEntity realm").getResultList();
for (Long expiration : eventExpirations) {
if (expiration > 0) {
int currentNumDeleted = em.createQuery("delete from EventEntity where realmId in (select realm.id from RealmEntity realm where realm.eventsExpiration = :expiration) and time < :eventTime")
.setParameter("expiration", expiration)
.setParameter("eventTime", currentTimeMillis - (expiration * 1000))
.executeUpdate();
logger.tracef("Deleted %d events for the expiration %d", currentNumDeleted, expiration);
numDeleted += currentNumDeleted;
}
}
logger.debugf("Cleared %d expired events in all realms", numDeleted);
} else {
session.realms().getRealmsStream().forEach(realm -> {
if (realm.isEventsEnabled() && realm.getEventsExpiration() > 0) {
long olderThan = Time.currentTimeMillis() - realm.getEventsExpiration() * 1000;
clear(realm.getId(), olderThan);
}
});
}
}
@Override @Override
public void onEvent(Event event) { public void onEvent(Event event) {
em.persist(convertEvent(event)); em.persist(convertEvent(event));

View file

@ -35,7 +35,7 @@ public class JpaEventStoreProviderFactory implements EventStoreProviderFactory {
@Override @Override
public EventStoreProvider create(KeycloakSession session) { public EventStoreProvider create(KeycloakSession session) {
JpaConnectionProvider connection = session.getProvider(JpaConnectionProvider.class); JpaConnectionProvider connection = session.getProvider(JpaConnectionProvider.class);
return new JpaEventStoreProvider(connection.getEntityManager(), maxDetailLength); return new JpaEventStoreProvider(session, connection.getEntityManager(), maxDetailLength);
} }
@Override @Override

View file

@ -34,6 +34,11 @@ public interface EventStoreProvider extends EventListenerProvider {
void clear(String realmId, long olderThan); void clear(String realmId, long olderThan);
/**
* Clear all expired events in all realms
*/
void clearExpiredEvents();
void clearAdmin(); void clearAdmin();
void clearAdmin(String realmId); void clearAdmin(String realmId);

View file

@ -35,6 +35,7 @@ import org.keycloak.models.KeycloakSessionFactory;
import org.keycloak.models.KeycloakSessionTask; import org.keycloak.models.KeycloakSessionTask;
import org.keycloak.models.KeycloakTransaction; import org.keycloak.models.KeycloakTransaction;
import org.keycloak.models.RealmModel; import org.keycloak.models.RealmModel;
import org.keycloak.models.RealmProvider;
import org.keycloak.models.RoleModel; import org.keycloak.models.RoleModel;
import org.keycloak.models.ScopeContainerModel; import org.keycloak.models.ScopeContainerModel;
import org.keycloak.models.UserCredentialModel; import org.keycloak.models.UserCredentialModel;
@ -691,4 +692,12 @@ public final class KeycloakModelUtils {
} }
} }
/**
* @return true if implementation of realmProvider is "jpa" . Which is always the case in standard Keycloak installations.
*/
public static boolean isRealmProviderJpa(KeycloakSession session) {
Set<String> providerIds = session.listProviderIds(RealmProvider.class);
return providerIds != null && providerIds.size() == 1 && providerIds.iterator().next().equals("jpa");
}
} }

View file

@ -17,6 +17,8 @@
package org.keycloak.services.scheduled; package org.keycloak.services.scheduled;
import org.jboss.logging.Logger;
import org.keycloak.common.util.Time;
import org.keycloak.events.EventStoreProvider; import org.keycloak.events.EventStoreProvider;
import org.keycloak.models.KeycloakSession; import org.keycloak.models.KeycloakSession;
import org.keycloak.timer.ScheduledTask; import org.keycloak.timer.ScheduledTask;
@ -26,17 +28,19 @@ import org.keycloak.timer.ScheduledTask;
*/ */
public class ClearExpiredEvents implements ScheduledTask { public class ClearExpiredEvents implements ScheduledTask {
protected static final Logger logger = Logger.getLogger(ClearExpiredEvents.class);
@Override @Override
public void run(KeycloakSession session) { public void run(KeycloakSession session) {
long currentTimeMillis = Time.currentTimeMillis();
EventStoreProvider eventStore = session.getProvider(EventStoreProvider.class); EventStoreProvider eventStore = session.getProvider(EventStoreProvider.class);
if (eventStore != null) { if (eventStore != null) {
session.realms().getRealmsStream().forEach(realm -> { eventStore.clearExpiredEvents();
if (realm.isEventsEnabled() && realm.getEventsExpiration() > 0) {
long olderThan = System.currentTimeMillis() - realm.getEventsExpiration() * 1000;
eventStore.clear(realm.getId(), olderThan);
}
});
} }
long took = Time.currentTimeMillis() - currentTimeMillis;
logger.debugf("ClearExpiredEvents finished in %d ms", took);
} }
} }

View file

@ -17,6 +17,8 @@
package org.keycloak.services.scheduled; package org.keycloak.services.scheduled;
import org.jboss.logging.Logger;
import org.keycloak.common.util.Time;
import org.keycloak.models.KeycloakSession; import org.keycloak.models.KeycloakSession;
import org.keycloak.models.UserSessionProvider; import org.keycloak.models.UserSessionProvider;
import org.keycloak.models.session.UserSessionPersisterProvider; import org.keycloak.models.session.UserSessionPersisterProvider;
@ -27,16 +29,23 @@ import org.keycloak.timer.ScheduledTask;
*/ */
public class ClearExpiredUserSessions implements ScheduledTask { public class ClearExpiredUserSessions implements ScheduledTask {
protected static final Logger logger = Logger.getLogger(ClearExpiredUserSessions.class);
public static final String TASK_NAME = "ClearExpiredUserSessions"; public static final String TASK_NAME = "ClearExpiredUserSessions";
@Override @Override
public void run(KeycloakSession session) { public void run(KeycloakSession session) {
long currentTimeMillis = Time.currentTimeMillis();
UserSessionProvider sessions = session.sessions(); UserSessionProvider sessions = session.sessions();
session.realms().getRealmsStream().forEach(realm -> { session.realms().getRealmsStream().forEach(realm -> {
sessions.removeExpired(realm); sessions.removeExpired(realm);
session.authenticationSessions().removeExpired(realm); session.authenticationSessions().removeExpired(realm);
session.getProvider(UserSessionPersisterProvider.class).removeExpired(realm); session.getProvider(UserSessionPersisterProvider.class).removeExpired(realm);
}); });
long took = Time.currentTimeMillis() - currentTimeMillis;
logger.debugf("ClearExpiredUserSessions finished in %d ms", took);
} }
} }

View file

@ -282,11 +282,11 @@ public class TestingResourceProvider implements RealmResourceProvider {
} }
@GET @GET
@Path("/clear-event-store-older-than") @Path("/clear-expired-events")
@Produces(MediaType.APPLICATION_JSON) @Produces(MediaType.APPLICATION_JSON)
public Response clearEventStore(@QueryParam("realmId") String realmId, @QueryParam("olderThan") long olderThan) { public Response clearExpiredEvents() {
EventStoreProvider eventStore = session.getProvider(EventStoreProvider.class); EventStoreProvider eventStore = session.getProvider(EventStoreProvider.class);
eventStore.clear(realmId, olderThan); eventStore.clearExpiredEvents();
return Response.noContent().build(); return Response.noContent().build();
} }

View file

@ -89,9 +89,9 @@ public interface TestingResource {
void clearEventStore(@QueryParam("realmId") String realmId); void clearEventStore(@QueryParam("realmId") String realmId);
@GET @GET
@Path("/clear-event-store-older-than") @Path("/clear-expired-events")
@Produces(MediaType.APPLICATION_JSON) @Produces(MediaType.APPLICATION_JSON)
void clearEventStore(@QueryParam("realmId") String realmId, @QueryParam("olderThan") long olderThan); void clearExpiredEvents();
/** /**
* Query events * Query events

View file

@ -21,17 +21,23 @@ import org.apache.commons.lang3.StringUtils;
import org.junit.After; import org.junit.After;
import org.junit.Assert; import org.junit.Assert;
import org.junit.Test; import org.junit.Test;
import org.keycloak.common.util.Time;
import org.keycloak.events.EventType; import org.keycloak.events.EventType;
import org.keycloak.events.log.JBossLoggingEventListenerProviderFactory;
import org.keycloak.representations.idm.EventRepresentation; import org.keycloak.representations.idm.EventRepresentation;
import org.keycloak.representations.idm.RealmRepresentation;
import org.keycloak.testsuite.arquillian.annotation.AuthServerContainerExclude; import org.keycloak.testsuite.arquillian.annotation.AuthServerContainerExclude;
import java.text.ParseException; import java.text.ParseException;
import java.text.SimpleDateFormat; import java.text.SimpleDateFormat;
import java.util.ArrayList;
import java.util.Date; import java.util.Date;
import java.util.HashMap; import java.util.HashMap;
import java.util.List;
import java.util.Map; import java.util.Map;
import org.keycloak.testsuite.arquillian.annotation.AuthServerContainerExclude.AuthServer; import org.keycloak.testsuite.arquillian.annotation.AuthServerContainerExclude.AuthServer;
import org.keycloak.testsuite.util.WaitUtils;
/** /**
* @author <a href="mailto:sthorger@redhat.com">Stian Thorgersen</a> * @author <a href="mailto:sthorger@redhat.com">Stian Thorgersen</a>
@ -39,6 +45,21 @@ import org.keycloak.testsuite.arquillian.annotation.AuthServerContainerExclude.A
*/ */
public class EventStoreProviderTest extends AbstractEventsTest { public class EventStoreProviderTest extends AbstractEventsTest {
@Override
public void addTestRealms(List<RealmRepresentation> testRealms) {
super.addTestRealms(testRealms);
for (String realmId : new String[] {"realmId", "realmId2"}) {
RealmRepresentation adminRealmRep = new RealmRepresentation();
adminRealmRep.setId(realmId);
adminRealmRep.setRealm(realmId);
adminRealmRep.setEnabled(true);
adminRealmRep.setEventsEnabled(true);
adminRealmRep.setEventsExpiration(0);
testRealms.add(adminRealmRep);
}
}
@After @After
public void after() { public void after() {
testing().clearEventStore(); testing().clearEventStore();
@ -175,15 +196,41 @@ public class EventStoreProviderTest extends AbstractEventsTest {
@Test @Test
public void clearOld() { public void clearOld() {
testing().onEvent(create(System.currentTimeMillis() - 30000, EventType.LOGIN, "realmId", "clientId", "userId", "127.0.0.1", "error")); testing().onEvent(create(System.currentTimeMillis() - 300000, EventType.LOGIN, "realmId", "clientId", "userId", "127.0.0.1", "error"));
testing().onEvent(create(System.currentTimeMillis() - 20000, EventType.LOGIN, "realmId", "clientId", "userId", "127.0.0.1", "error")); testing().onEvent(create(System.currentTimeMillis() - 200000, EventType.LOGIN, "realmId", "clientId", "userId", "127.0.0.1", "error"));
testing().onEvent(create(System.currentTimeMillis(), EventType.LOGIN, "realmId", "clientId", "userId", "127.0.0.1", "error")); testing().onEvent(create(System.currentTimeMillis(), EventType.LOGIN, "realmId", "clientId", "userId", "127.0.0.1", "error"));
testing().onEvent(create(System.currentTimeMillis(), EventType.LOGIN, "realmId", "clientId", "userId", "127.0.0.1", "error")); testing().onEvent(create(System.currentTimeMillis(), EventType.LOGIN, "realmId", "clientId", "userId", "127.0.0.1", "error"));
testing().onEvent(create(System.currentTimeMillis() - 30000, EventType.LOGIN, "realmId2", "clientId", "userId", "127.0.0.1", "error")); testing().onEvent(create(System.currentTimeMillis() - 300000, EventType.LOGIN, "realmId2", "clientId", "userId", "127.0.0.1", "error"));
testing().onEvent(create(System.currentTimeMillis(), EventType.LOGIN, "realmId2", "clientId", "userId", "127.0.0.1", "error"));
testing().clearEventStore("realmId", System.currentTimeMillis() - 10000); // Set expiration of events for "realmId" .
RealmRepresentation realm = realmsResouce().realm("realmId").toRepresentation();
realm.setEventsExpiration(100);
realmsResouce().realm("realmId").update(realm);
// The first 2 events from realmId will be deleted
testing().clearExpiredEvents();
Assert.assertEquals(4, testing().queryEvents(null, null, null, null, null, null, null, null, null).size());
// Set expiration of events for realmId2 as well
RealmRepresentation realm2 = realmsResouce().realm("realmId2").toRepresentation();
realm2.setEventsExpiration(100);
realmsResouce().realm("realmId2").update(realm2);
// The first event from "realmId2" will be deleted now
testing().clearExpiredEvents();
Assert.assertEquals(3, testing().queryEvents(null, null, null, null, null, null, null, null, null).size()); Assert.assertEquals(3, testing().queryEvents(null, null, null, null, null, null, null, null, null).size());
// set time offset to the future. The remaining 2 events from "realmId" and 1 event from "realmId2" should be expired now
setTimeOffset(150);
testing().clearExpiredEvents();
Assert.assertEquals(0, testing().queryEvents(null, null, null, null, null, null, null, null, null).size());
// Revert expirations
realm.setEventsExpiration(0);
realmsResouce().realm("realmId").update(realm);
realm2.setEventsExpiration(0);
realmsResouce().realm("realmId2").update(realm2);
} }
private EventRepresentation create(EventType event, String realmId, String clientId, String userId, String ipAddress, String error) { private EventRepresentation create(EventType event, String realmId, String clientId, String userId, String ipAddress, String error) {