Merge pull request #1753 from mposolda/master

KEYCLOAK-1952 Migration fix. Change some INFO messages to DEBUG/TRACE

connections/jpa-liquibase/src/main/resources/META-INF/jpa-changelog-1.6.0.xml

@@ -3,7 +3,7 @@
     <changeSet author="mposolda@redhat.com" id="1.6.0">
 
         <addColumn tableName="REALM">
-            <column name="OFFLINE_SESSION_IDLE_TIMEOUT" type="INT"/>
+            <column name="OFFLINE_SESSION_IDLE_TIMEOUT" type="INT" defaultValueNumeric="0"/>
             <column name="REVOKE_REFRESH_TOKEN" type="BOOLEAN" defaultValueBoolean="false">
                 <constraints nullable="false"/>
             </column>

model/sessions-infinispan/src/main/java/org/keycloak/models/sessions/infinispan/initializer/InfinispanUserSessionInitializer.java

@@ -161,13 +161,13 @@ public class InfinispanUserSessionInitializer {
                 int nodesCount = transport==null ? 1 : transport.getMembers().size();
                 int distributedWorkersCount = processors * nodesCount;
 
-                // TODO: debug
+                log.debugf("Starting next iteration with %d workers", distributedWorkersCount);
-                log.infof("Starting next iteration with %d workers", distributedWorkersCount);
 
                 List<Integer> segments = state.getUnfinishedSegments(distributedWorkersCount);
 
-                // TODO: trace
+                if (log.isTraceEnabled()) {
-                log.info("unfinished segments for this iteration: " + segments);
+                    log.trace("unfinished segments for this iteration: " + segments);
+                }
 
                 List<Future<WorkerResult>> futures = new LinkedList<>();
                 for (Integer segment : segments) {
@@ -205,8 +205,9 @@ public class InfinispanUserSessionInitializer {
 
                 saveStateToCache(state);
 
-                // TODO
+                if (log.isDebugEnabled()) {
-                log.info("New initializer state pushed. The state is: " + state.printState());
+                    log.debug("New initializer state pushed. The state is: " + state.printState());
+                }
             }
         } finally {
             distributedExecutorService.shutdown();
@@ -235,8 +236,7 @@ public class InfinispanUserSessionInitializer {
         @ViewChanged
         public void viewChanged(ViewChangedEvent event) {
             boolean isCoordinator = isCoordinator();
-            // TODO: debug
+            log.debug("View Changed: is coordinator: " + isCoordinator);
-            log.info("View Changed: is coordinator: " + isCoordinator);
 
             if (isCoordinator) {
                 latch.countDown();

model/sessions-infinispan/src/main/java/org/keycloak/models/sessions/infinispan/initializer/InitializerState.java

@@ -26,8 +26,7 @@ public class InitializerState extends SessionEntity {
             segmentsCount = segmentsCount + 1;
         }
 
-        // TODO: debug
+        log.debugf("sessionsCount: %d, sessionsPerSegment: %d, segmentsCount: %d", sessionsCount, sessionsPerSegment, segmentsCount);
-        log.infof("sessionsCount: %d, sessionsPerSegment: %d, segmentsCount: %d", sessionsCount, sessionsPerSegment, segmentsCount);
 
         for (int i=0 ; i<segmentsCount ; i++) {
             segments.add(false);

model/sessions-infinispan/src/main/java/org/keycloak/models/sessions/infinispan/initializer/OfflineUserSessionLoader.java

@@ -20,8 +20,7 @@ public class OfflineUserSessionLoader implements SessionLoader {
         UserSessionPersisterProvider persister = session.getProvider(UserSessionPersisterProvider.class);
         int startTime = (int)(session.getKeycloakSessionFactory().getServerStartupTimestamp() / 1000);
 
-        // TODO: debug
+        log.debugf("Clearing detached sessions from persistent storage and updating timestamps to %d", startTime);
-        log.infof("Clearing detached sessions from persistent storage and updating timestamps to %d", startTime);
 
         persister.clearDetachedUserSessions();
         persister.updateAllTimestamps(startTime);
@@ -35,8 +34,9 @@ public class OfflineUserSessionLoader implements SessionLoader {
 
     @Override
     public boolean loadSessions(KeycloakSession session, int first, int max) {
-        // TODO: trace
+        if (log.isTraceEnabled()) {
-        log.infof("Loading sessions - first: %d, max: %d", first, max);
+            log.tracef("Loading sessions - first: %d, max: %d", first, max);
+        }
 
         UserSessionPersisterProvider persister = session.getProvider(UserSessionPersisterProvider.class);
         List<UserSessionModel> sessions = persister.loadUserSessions(first, max, true);

model/sessions-infinispan/src/main/java/org/keycloak/models/sessions/infinispan/initializer/SessionInitializerWorker.java

@@ -38,8 +38,9 @@ public class SessionInitializerWorker implements DistributedCallable<String, Ses
 
     @Override
     public InfinispanUserSessionInitializer.WorkerResult call() throws Exception {
-        // TODO
+        if (log.isTraceEnabled()) {
-        log.infof("Running computation for segment: %d", segment);
+            log.tracef("Running computation for segment: %d", segment);
+        }
 
         KeycloakSessionFactory sessionFactory = cache.getAdvancedCache().getComponentRegistry().getComponent(KeycloakSessionFactory.class);
         if (sessionFactory == null) {

testsuite/integration/src/test/resources/log4j.properties

@@ -18,6 +18,9 @@ log4j.logger.org.keycloak=info
 keycloak.liquibase.logging.level=info
 log4j.logger.org.keycloak.connections.jpa.updater.liquibase.LiquibaseJpaUpdaterProvider=${keycloak.liquibase.logging.level}
 
+# Enable to view infinispan initialization
+# log4j.logger.org.keycloak.models.sessions.infinispan.initializer=trace
+
 # Enable to view database updates
 # log4j.logger.org.keycloak.connections.mongo.updater.DefaultMongoUpdaterProvider=debug
 # log4j.logger.org.keycloak.connections.jpa.DefaultJpaConnectionProviderFactory=debug