Testsuite PoC - Add ability to obtain events in tests using Syslog (#32304)

Closes #32303

Signed-off-by: stianst <stianst@gmail.com>

test-poc/examples/src/test/java/org/keycloak/test/examples/EventsTest.java

@@ -0,0 +1,60 @@
+package org.keycloak.test.examples;
+
+import com.nimbusds.oauth2.sdk.GeneralException;
+import org.junit.jupiter.api.Assertions;
+import org.junit.jupiter.api.Test;
+import org.keycloak.events.EventType;
+import org.keycloak.test.framework.annotations.InjectEvents;
+import org.keycloak.test.framework.annotations.InjectOAuthClient;
+import org.keycloak.test.framework.annotations.InjectPage;
+import org.keycloak.test.framework.annotations.InjectWebDriver;
+import org.keycloak.test.framework.annotations.KeycloakIntegrationTest;
+import org.keycloak.test.framework.events.Events;
+import org.keycloak.test.framework.oauth.OAuthClient;
+import org.keycloak.test.framework.page.LoginPage;
+import org.keycloak.test.framework.server.KeycloakTestServerConfig;
+import org.openqa.selenium.WebDriver;
+
+import java.io.IOException;
+import java.net.URL;
+
+@KeycloakIntegrationTest(config = EventsTest.ServerConfig.class)
+public class EventsTest {
+
+    @InjectEvents
+    private Events events;
+
+    @InjectOAuthClient
+    private OAuthClient oAuthClient;
+
+    @InjectWebDriver
+    private WebDriver webDriver;
+
+    @InjectPage
+    private LoginPage loginPage;
+
+    @Test
+    public void testFailedLogin() throws GeneralException, IOException {
+        URL authorizationRequestURL = oAuthClient.authorizationRequest();
+        webDriver.navigate().to(authorizationRequestURL);
+        loginPage.fillLogin("invalid", "invalid");
+        loginPage.submit();
+
+        Assertions.assertEquals(EventType.LOGIN_ERROR, events.poll().getType());
+    }
+
+    @Test
+    public void testClientLogin() throws GeneralException, IOException {
+        oAuthClient.clientCredentialGrant();
+
+        Assertions.assertEquals(EventType.CLIENT_LOGIN, events.poll().getType());
+    }
+
+    public static class ServerConfig implements KeycloakTestServerConfig {
+        @Override
+        public boolean enableSysLog() {
+            return true;
+        }
+    }
+
+}

test-poc/examples/src/test/resources/logging.properties

@@ -1,5 +1,5 @@
 loggers=org.keycloak.test
-logger.org.keycloak.test.level=TRACE
+#logger.org.keycloak.test.level=TRACE
 
 logger.handlers=CONSOLE
 

test-poc/framework/src/main/java/org/keycloak/test/framework/KeycloakIntegrationTestExtension.java

@@ -35,23 +35,10 @@ public class KeycloakIntegrationTestExtension implements BeforeEachCallback, Aft
     }
 
     private Registry getRegistry(ExtensionContext context) {
-        ExtensionContext.Store store = getStore(context);
+        ExtensionContext.Store store = context.getRoot().getStore(ExtensionContext.Namespace.GLOBAL);
-        Registry registry = (Registry) store.getOrComputeIfAbsent(Registry.class, r -> createRegistry());
+        Registry registry = (Registry) store.getOrComputeIfAbsent(Registry.class, r -> new Registry());
         registry.setCurrentContext(context);
         return registry;
     }
 
-    private ExtensionContext.Store getStore(ExtensionContext context) {
-        while (context.getParent().isPresent()) {
-            context = context.getParent().get();
-        }
-        return context.getStore(ExtensionContext.Namespace.create(getClass()));
-    }
-
-    private Registry createRegistry() {
-        Registry registry = new Registry();
-        Runtime.getRuntime().addShutdownHook(new Thread(registry::close));
-        return registry;
-    }
-
 }

test-poc/framework/src/main/java/org/keycloak/test/framework/annotations/InjectEvents.java

@@ -0,0 +1,11 @@
+package org.keycloak.test.framework.annotations;
+
+import java.lang.annotation.ElementType;
+import java.lang.annotation.Retention;
+import java.lang.annotation.RetentionPolicy;
+import java.lang.annotation.Target;
+
+@Retention(RetentionPolicy.RUNTIME)
+@Target(ElementType.FIELD)
+public @interface InjectEvents {
+}

test-poc/framework/src/main/java/org/keycloak/test/framework/annotations/InjectSysLogServer.java

@@ -0,0 +1,11 @@
+package org.keycloak.test.framework.annotations;
+
+import java.lang.annotation.ElementType;
+import java.lang.annotation.Retention;
+import java.lang.annotation.RetentionPolicy;
+import java.lang.annotation.Target;
+
+@Retention(RetentionPolicy.RUNTIME)
+@Target(ElementType.FIELD)
+public @interface InjectSysLogServer {
+}

test-poc/framework/src/main/java/org/keycloak/test/framework/events/EventParser.java

@@ -0,0 +1,62 @@
+package org.keycloak.test.framework.events;
+
+import org.keycloak.events.Event;
+import org.keycloak.events.EventType;
+
+import java.util.HashMap;
+import java.util.Map;
+
+public class EventParser {
+
+    private EventParser() {
+    }
+
+    public static Event parse(SysLog sysLog) {
+        if (!sysLog.getCategory().equals("org.keycloak.events")) {
+            return null;
+        }
+
+        String message = sysLog.getMessage().substring(sysLog.getMessage().indexOf(')') + 1).trim();
+
+        if (!message.startsWith("type=")) {
+            return null;
+        }
+
+        String[] split = message.split(", ");
+
+        Map<String, String> eventMap = new HashMap<>();
+        for (String s : split) {
+            String[] split1 = s.split("=");
+            eventMap.put(split1[0], split1[1].substring(1, split1[1].length() - 1));
+        }
+
+        Event event = new Event();
+        event.setTime(sysLog.getTimestamp().getTime() / 1000);
+        event.setDetails(new HashMap<>());
+
+        for (Map.Entry<String, String> e : eventMap.entrySet()) {
+            switch (e.getKey()) {
+                case "type":
+                    event.setType(EventType.valueOf(e.getValue()));
+                    break;
+                case "clientId":
+                    event.setClientId(e.getValue());
+                    break;
+                case "realmId":
+                    event.setRealmId(e.getValue());
+                    break;
+                case "sessionId":
+                    event.setSessionId(e.getValue());
+                    break;
+                case "ipAddress":
+                    event.setIpAddress(e.getValue());
+                default:
+                    event.getDetails().put(e.getKey(), e.getValue());
+                    break;
+            }
+        }
+
+        return event;
+    }
+
+}

test-poc/framework/src/main/java/org/keycloak/test/framework/events/Events.java

@@ -0,0 +1,28 @@
+package org.keycloak.test.framework.events;
+
+import org.keycloak.events.Event;
+
+import java.util.concurrent.BlockingQueue;
+import java.util.concurrent.LinkedBlockingQueue;
+import java.util.concurrent.TimeUnit;
+
+public class Events implements SysLogListener {
+
+    private final BlockingQueue<Event> events = new LinkedBlockingQueue<>();
+
+    public Event poll() {
+        try {
+            return events.poll(30, TimeUnit.SECONDS);
+        } catch (InterruptedException e) {
+            return null;
+        }
+    }
+
+    @Override
+    public void onLog(SysLog sysLog) {
+        Event event = EventParser.parse(sysLog);
+        if (event != null) {
+            events.add(event);
+        }
+    }
+}

test-poc/framework/src/main/java/org/keycloak/test/framework/events/EventsSupplier.java

@@ -0,0 +1,47 @@
+package org.keycloak.test.framework.events;
+
+import org.keycloak.test.framework.annotations.InjectEvents;
+import org.keycloak.test.framework.injection.InstanceContext;
+import org.keycloak.test.framework.injection.LifeCycle;
+import org.keycloak.test.framework.injection.RequestedInstance;
+import org.keycloak.test.framework.injection.Supplier;
+
+public class EventsSupplier implements Supplier<Events, InjectEvents> {
+    @Override
+    public Class<InjectEvents> getAnnotationClass() {
+        return InjectEvents.class;
+    }
+
+    @Override
+    public Class<Events> getValueType() {
+        return Events.class;
+    }
+
+    @Override
+    public Events getValue(InstanceContext<Events, InjectEvents> instanceContext) {
+        Events events = new Events();
+        SysLogServer sysLogServer = instanceContext.getDependency(SysLogServer.class);
+        instanceContext.addNote("server", sysLogServer);
+        return events;
+    }
+
+    @Override
+    public void onBeforeEach(InstanceContext<Events, InjectEvents> instanceContext) {
+        instanceContext.getNote("server", SysLogServer.class).addListener(instanceContext.getValue());
+    }
+
+    @Override
+    public LifeCycle getDefaultLifecycle() {
+        return LifeCycle.METHOD;
+    }
+
+    @Override
+    public void close(InstanceContext<Events, InjectEvents> instanceContext) {
+        instanceContext.getNote("server", SysLogServer.class).removeListener(instanceContext.getValue());
+    }
+
+    @Override
+    public boolean compatible(InstanceContext<Events, InjectEvents> a, RequestedInstance<Events, InjectEvents> b) {
+        return true;
+    }
+}

test-poc/framework/src/main/java/org/keycloak/test/framework/events/SysLog.java

@@ -0,0 +1,52 @@
+package org.keycloak.test.framework.events;
+
+import java.time.Instant;
+import java.util.Date;
+
+public class SysLog {
+
+    private static final String SEPARATOR = " - \uFEFF";
+
+    private Date timestamp;
+    private String hostname;
+    private String appName;
+    private String category;
+    private String message;
+
+    private SysLog() {
+    }
+
+    public static SysLog parse(String logEntry) {
+        int i = logEntry.indexOf(SEPARATOR);
+
+        String[] header = logEntry.substring(0, i).split(" ");
+
+        SysLog sysLog = new SysLog();
+        sysLog.timestamp = Date.from(Instant.parse(header[1]));
+        sysLog.hostname = header[2];
+        sysLog.appName = header[3];
+        sysLog.category = header[5];
+        sysLog.message = logEntry.substring(i + SEPARATOR.length());
+        return sysLog;
+    }
+
+    public Date getTimestamp() {
+        return timestamp;
+    }
+
+    public String getHostname() {
+        return hostname;
+    }
+
+    public String getAppName() {
+        return appName;
+    }
+
+    public String getCategory() {
+        return category;
+    }
+
+    public String getMessage() {
+        return message;
+    }
+}

test-poc/framework/src/main/java/org/keycloak/test/framework/events/SysLogListener.java

@@ -0,0 +1,7 @@
+package org.keycloak.test.framework.events;
+
+public interface SysLogListener {
+
+    void onLog(SysLog sysLog);
+
+}

test-poc/framework/src/main/java/org/keycloak/test/framework/events/SysLogServer.java

@@ -0,0 +1,93 @@
+package org.keycloak.test.framework.events;
+
+import org.jboss.logging.Logger;
+
+import java.io.BufferedReader;
+import java.io.IOException;
+import java.io.InputStreamReader;
+import java.net.ServerSocket;
+import java.net.Socket;
+import java.util.Collections;
+import java.util.HashSet;
+import java.util.LinkedList;
+import java.util.List;
+import java.util.Set;
+
+public class SysLogServer {
+
+    private static final Logger LOGGER = Logger.getLogger(SysLogServer.class);
+    private static final int MAX_THREADS = 5;
+    private ServerSocket serverSocket;
+    private final List<Thread> threads = Collections.synchronizedList(new LinkedList<>());
+    private final Set<SysLogListener> listeners = new HashSet<>();
+    private boolean running = true;
+
+    public void start() throws IOException {
+        serverSocket = new ServerSocket(0);
+        startThread();
+    }
+
+    public void stop() throws InterruptedException, IOException {
+        LOGGER.tracev("Shutdown, threads={0}", threads.size());
+        running = false;
+        serverSocket.close();
+        for (Thread t : threads) {
+            t.join();
+        }
+    }
+
+    public void addListener(SysLogListener listener) {
+        listeners.add(listener);
+    }
+
+    public void removeListener(SysLogListener listener) {
+        listeners.remove(listener);
+    }
+
+    public String getEndpoint() {
+        return "localhost:" + serverSocket.getLocalPort();
+    }
+
+    protected void startThread() {
+        if (running && threads.size() < MAX_THREADS) {
+            Thread thread = new Thread(new BasicSocketHandler());
+            thread.start();
+            threads.add(thread);
+
+            LOGGER.tracev("Started new thread, running threads={0}", threads.size());
+        }
+    }
+
+    private class BasicSocketHandler implements Runnable {
+
+        @Override
+        public void run() {
+            while (running) {
+                try {
+                    Socket socket = serverSocket.accept();
+                    LOGGER.trace("Socket accepted");
+                    startThread();
+
+                    BufferedReader br = new BufferedReader(new InputStreamReader(socket.getInputStream()));
+                    for (String l = br.readLine(); l != null; l = br.readLine()) {
+                        try {
+                            SysLog sysLog = SysLog.parse(l);
+// TODO This shows an issue when using embedded Keycloak server logging from the testsuite (client side) is also sent over syslog :/
+//                            LOGGER.tracev("New message={0}", sysLog.getMessage());
+                            listeners.forEach(listener -> listener.onLog(sysLog));
+                        } catch (Throwable t) {
+                            LOGGER.tracev("Failed to parse message={0}", l);
+                        }
+                    }
+                    socket.close();
+                    LOGGER.trace("Socket closed");
+                } catch (Throwable t) {
+                    if (!serverSocket.isClosed()) {
+                        LOGGER.trace(t.getMessage(), t);
+                    }
+                }
+            }
+        }
+    }
+
+}

test-poc/framework/src/main/java/org/keycloak/test/framework/events/SysLogServerSupplier.java

@@ -0,0 +1,52 @@
+package org.keycloak.test.framework.events;
+
+import org.keycloak.test.framework.annotations.InjectSysLogServer;
+import org.keycloak.test.framework.injection.InstanceContext;
+import org.keycloak.test.framework.injection.LifeCycle;
+import org.keycloak.test.framework.injection.RequestedInstance;
+import org.keycloak.test.framework.injection.Supplier;
+
+import java.io.IOException;
+
+public class SysLogServerSupplier implements Supplier<SysLogServer, InjectSysLogServer> {
+    @Override
+    public Class<InjectSysLogServer> getAnnotationClass() {
+        return InjectSysLogServer.class;
+    }
+
+    @Override
+    public Class<SysLogServer> getValueType() {
+        return SysLogServer.class;
+    }
+
+    @Override
+    public SysLogServer getValue(InstanceContext<SysLogServer, InjectSysLogServer> instanceContext) {
+        try {
+            SysLogServer server = new SysLogServer();
+            server.start();
+            return server;
+        } catch (IOException e) {
+            throw new RuntimeException(e);
+        }
+    }
+
+    @Override
+    public LifeCycle getDefaultLifecycle() {
+        return LifeCycle.GLOBAL;
+    }
+
+    @Override
+    public void close(InstanceContext<SysLogServer, InjectSysLogServer> instanceContext) {
+        SysLogServer server = instanceContext.getValue();
+        try {
+            server.stop();
+        } catch (Exception e) {
+            throw new RuntimeException(e);
+        }
+    }
+
+    @Override
+    public boolean compatible(InstanceContext<SysLogServer, InjectSysLogServer> a, RequestedInstance<SysLogServer, InjectSysLogServer> b) {
+        return true;
+    }
+}

test-poc/framework/src/main/java/org/keycloak/test/framework/injection/Registry.java

@@ -19,7 +19,7 @@ import java.util.Set;
 import java.util.stream.Collectors;
 
 @SuppressWarnings({"rawtypes", "unchecked"})
-public class Registry {
+public class Registry implements ExtensionContext.Store.CloseableResource {
 
     private static final Logger LOGGER = Logger.getLogger(Registry.class);
 
@@ -127,6 +127,7 @@ public class Registry {
         matchDeployedInstancesWithRequestedInstances();
         deployRequestedInstances();
         injectFields(testInstance);
+        invokeBeforeEachOnSuppliers();
     }
 
     private void findRequestedInstances(Object testInstance) {
@@ -344,4 +345,10 @@ public class Registry {
                 .findFirst().orElse(null);
     }
 
+    private void invokeBeforeEachOnSuppliers() {
+        for (InstanceContext i : deployedInstances) {
+            i.getSupplier().onBeforeEach(i);
+        }
+    }
+
 }

test-poc/framework/src/main/java/org/keycloak/test/framework/injection/Supplier.java

@@ -31,4 +31,7 @@ public interface Supplier<T, S extends Annotation> {
         return getClass().getSimpleName();
     }
 
+    default void onBeforeEach(InstanceContext<T, S> instanceContext) {
+    }
+
 }

test-poc/framework/src/main/java/org/keycloak/test/framework/server/AbstractKeycloakTestServerSupplier.java

@@ -3,6 +3,7 @@ package org.keycloak.test.framework.server;
 import org.keycloak.test.framework.annotations.KeycloakIntegrationTest;
 import org.keycloak.test.framework.config.Config;
 import org.keycloak.test.framework.database.TestDatabase;
+import org.keycloak.test.framework.events.SysLogServer;
 import org.keycloak.test.framework.injection.InstanceContext;
 import org.keycloak.test.framework.injection.LifeCycle;
 import org.keycloak.test.framework.injection.RequestedInstance;
@@ -36,6 +37,14 @@ public abstract class AbstractKeycloakTestServerSupplier implements Supplier<Key
         rawOptions.add("--bootstrap-admin-client-id=" + Config.getAdminClientId());
         rawOptions.add("--bootstrap-admin-client-secret=" + Config.getAdminClientSecret());
 
+        if (serverConfig.enableSysLog()) {
+            SysLogServer sysLogServer = instanceContext.getDependency(SysLogServer.class);
+
+            rawOptions.add("--log=console,syslog");
+            rawOptions.add("--log-syslog-endpoint=" + sysLogServer.getEndpoint());
+            rawOptions.add("--spi-events-listener-jboss-logging-success-level=INFO");
+        }
+
         if (!serverConfig.features().isEmpty()) {
             rawOptions.add("--features=" + String.join(",", serverConfig.features()));
         }

test-poc/framework/src/main/java/org/keycloak/test/framework/server/KeycloakTestServerConfig.java

@@ -14,4 +14,6 @@ public interface KeycloakTestServerConfig {
         return Collections.emptySet();
     }
 
+    default boolean enableSysLog() { return false; }
+
 }

test-poc/framework/src/main/resources/META-INF/services/org.keycloak.test.framework.injection.Supplier

@@ -2,8 +2,8 @@ org.keycloak.test.framework.admin.KeycloakAdminClientSupplier
 org.keycloak.test.framework.realm.ClientSupplier
 org.keycloak.test.framework.realm.RealmSupplier
 org.keycloak.test.framework.realm.UserSupplier
-org.keycloak.test.framework.server.EmbeddedKeycloakTestServerSupplier
 org.keycloak.test.framework.server.DistributionKeycloakTestServerSupplier
+org.keycloak.test.framework.server.EmbeddedKeycloakTestServerSupplier
 org.keycloak.test.framework.server.RemoteKeycloakTestServerSupplier
 org.keycloak.test.framework.webdriver.ChromeHeadlessWebDriverSupplier
 org.keycloak.test.framework.webdriver.ChromeWebDriverSupplier
@@ -18,3 +18,5 @@ org.keycloak.test.framework.database.MSSQLServerDatabaseSupplier
 org.keycloak.test.framework.database.OracleDatabaseSupplier
 org.keycloak.test.framework.page.PageSupplier
 org.keycloak.test.framework.oauth.OAuthClientSupplier
+org.keycloak.test.framework.events.SysLogServerSupplier
+org.keycloak.test.framework.events.EventsSupplier

test-poc/framework/src/test/java/org/keycloak/test/framework/events/EventParserTest.java

@@ -0,0 +1,29 @@
+package org.keycloak.test.framework.events;
+
+import org.junit.jupiter.api.Assertions;
+import org.junit.jupiter.api.Test;
+import org.keycloak.events.Event;
+
+public class EventParserTest {
+
+    String nonEvent = "<14>1 2024-08-21T08:14:33.591+02:00 fedora keycloak 17377 org.keycloak.category - \uFEFF2024-08-21 08:14:33,591 INFO  [org.keycloak.events] (executor-thread-12) type=\"LOGIN\"";
+    String loginEvent = "<14>1 2024-08-21T08:14:33.591+02:00 fedora keycloak 17377 org.keycloak.events - \uFEFF2024-08-21 08:14:33,591 INFO  [org.keycloak.events] (executor-thread-12) type=\"LOGIN\", realmId=\"c4730c14-e66f-4372-89df-9910e769f3b9\", realmName=\"master\", clientId=\"security-admin-console\", userId=\"c89c95c1-633a-4116-b68c-1b78aa27c556\", sessionId=\"3186fe6a-5e85-4d0d-b517-2835369db2b9\", ipAddress=\"0:0:0:0:0:0:0:1\", auth_method=\"openid-connect\", auth_type=\"code\", response_type=\"code\", redirect_uri=\"http://localhost:8080/admin/master/console/#/master/users/c89c95c1-633a-4116-b68c-1b78aa27c556/settings\", consent=\"no_consent_required\", code_id=\"3186fe6a-5e85-4d0d-b517-2835369db2b9\", response_mode=\"query\", username=\"admin\", authSessionParentId=\"3186fe6a-5e85-4d0d-b517-2835369db2b9\", authSessionTabId=\"iL5xM2eOOcc\"";
+    String adminEvent = "<14>1 2024-08-21T08:15:13.688+02:00 fedora keycloak 17377 org.keycloak.events - \uFEFF2024-08-21 08:15:13,688 INFO  [org.keycloak.events] (executor-thread-18) operationType=\"UPDATE\", realmId=\"c4730c14-e66f-4372-89df-9910e769f3b9\", realmName=\"master\", clientId=\"0a7da22d-b13e-4696-9526-3e2cde55a64c\", userId=\"c89c95c1-633a-4116-b68c-1b78aa27c556\", ipAddress=\"0:0:0:0:0:0:0:1\", resourceType=\"USER\", resourcePath=\"users/c89c95c1-633a-4116-b68c-1b78aa27c556\"";
+
+    @Test
+    public void testParseLoginEvent() {
+        Event event = EventParser.parse(SysLog.parse(loginEvent));
+        Assertions.assertEquals("security-admin-console", event.getClientId());
+    }
+
+    @Test
+    public void testParseNonEvent() {
+        Assertions.assertNull(EventParser.parse(SysLog.parse(nonEvent)));
+    }
+
+    @Test
+    public void testParseAdminEvent() {
+        Assertions.assertNull(EventParser.parse(SysLog.parse(adminEvent)));
+    }
+
+}

test-poc/framework/src/test/java/org/keycloak/test/framework/events/SysLogTest.java

@@ -0,0 +1,21 @@
+package org.keycloak.test.framework.events;
+
+import org.junit.jupiter.api.Assertions;
+import org.junit.jupiter.api.Test;
+
+public class SysLogTest {
+
+    String logEntry = "<14>1 2024-08-21T08:14:33.591+02:00 fedora keycloak 17377 org.keycloak.category - \uFEFFSome log message";
+
+    @Test
+    public void testParseLog() {
+        SysLog sysLog = SysLog.parse(logEntry);
+
+        Assertions.assertNotNull(sysLog.getTimestamp());
+        Assertions.assertEquals("fedora", sysLog.getHostname());
+        Assertions.assertEquals("keycloak", sysLog.getAppName());
+        Assertions.assertEquals("org.keycloak.category", sysLog.getCategory());
+        Assertions.assertEquals("Some log message", sysLog.getMessage());
+    }
+
+}

test-poc/framework/src/test/resources/logging.properties

@@ -1,5 +1,5 @@
 loggers=org.keycloak.test
-logger.org.keycloak.test.level=TRACE
+#logger.org.keycloak.test.level=TRACE
 
 logger.handlers=CONSOLE