diff --git a/src/main/java/org/appng/tomcat/session/Session.java b/src/main/java/org/appng/tomcat/session/Session.java index c12dda1..fd2f593 100644 --- a/src/main/java/org/appng/tomcat/session/Session.java +++ b/src/main/java/org/appng/tomcat/session/Session.java @@ -115,16 +115,22 @@ public SessionData serialize(String alternativeSiteName) throws IOException { } } - public static Session create(Manager manager, SessionData sessionData) throws IOException, ClassNotFoundException { + public static Session load(Manager manager, SessionData sessionData) + throws IOException, ClassNotFoundException { + Session session = null; try (ByteArrayInputStream is = new ByteArrayInputStream(sessionData.getData()); ObjectInputStream ois = Utils.getObjectInputStream(is, sessionData.getSite(), manager.getContext())) { - Session session = (Session) manager.createEmptySession(); - session.readObjectData(ois); - session.access(); - session.setClean(); - manager.add(session); - return session; + Session loadedSession = (Session) manager.createEmptySession(); + loadedSession.readObjectData(ois); + // isValid() calls manager.remove(session, true) in case the session expired + if (loadedSession.isValid()) { + session = loadedSession; + session.access(); + session.setClean(); + manager.add(session); + } } + return session; } } diff --git a/src/main/java/org/appng/tomcat/session/SessionData.java b/src/main/java/org/appng/tomcat/session/SessionData.java index 2582022..23f75b0 100644 --- a/src/main/java/org/appng/tomcat/session/SessionData.java +++ b/src/main/java/org/appng/tomcat/session/SessionData.java @@ -51,6 +51,10 @@ public String getId() { return id; } + /** + * last accessed time in milliseconds + * @return milliseconds since last access + */ public long getLastAccessed() { return lastAccessed; } @@ -68,9 +72,8 @@ public int checksum() { return checksum; } - public boolean shouldExpire() { - long timeIdle = (System.currentTimeMillis() - maxInactiveInterval) / 1000L; - return timeIdle >= maxInactiveInterval + TimeUnit.MINUTES.toSeconds(5); + public long secondsSinceAccessed() { + return (System.currentTimeMillis() - lastAccessed) / 1000; } } diff --git a/src/main/java/org/appng/tomcat/session/SessionManager.java b/src/main/java/org/appng/tomcat/session/SessionManager.java index 9bd31f9..b8c5674 100644 --- a/src/main/java/org/appng/tomcat/session/SessionManager.java +++ b/src/main/java/org/appng/tomcat/session/SessionManager.java @@ -16,59 +16,77 @@ package org.appng.tomcat.session; import java.io.IOException; -import java.util.Arrays; +import java.util.Date; import java.util.Locale; -import java.util.concurrent.atomic.AtomicInteger; import org.apache.catalina.LifecycleException; import org.apache.catalina.LifecycleState; import org.apache.catalina.session.ManagerBase; import org.apache.juli.logging.Log; +/** + * Basic implementation of {@link ManagerBase} using a persistent storage. + * + * @param + * the type of the persistent storage + */ public abstract class SessionManager extends ManagerBase { private static final double NANOS_TO_MILLIS = 1000000d; protected boolean sticky = true; + protected int sessionSaveIntervalSeconds = 10; + + /** + * Updates the session in the persistent storage. + * + * @param id + * the id of the session + * @param sessionData + * the session's {@link SessionData} + * + * @throws IOException + * if an error occurs while updating the session + */ protected abstract void updateSession(String id, SessionData sessionData) throws IOException; + /** + * Retrieves the {@link SessionData} from the persistent storage + * + * @param id + * the id of the session + * + * @return the {@link SessionData} of the session, or {@code null} if the session could not be found + * + * @throws IOException + * if an error occurs while retrieving the data + */ protected abstract SessionData findSessionInternal(String id) throws IOException; - public abstract void removeInternal(org.apache.catalina.Session session, boolean update); + /** + * Remove the session from the underlying persistent storage + * + * @param session + * the session to remove + */ + public abstract void removeInternal(org.apache.catalina.Session session); public abstract Log log(); + /** + * Returns the persistent storage. + * + * @return the persistent storage + */ protected abstract T getPersistentSessions(); - // protected abstract int expireInternal(); - @Override protected void stopInternal() throws LifecycleException { super.stopInternal(); setState(LifecycleState.STOPPING); } - @Override - public void processExpires() { - long timeNow = System.currentTimeMillis(); - org.apache.catalina.Session sessions[] = findSessions(); - AtomicInteger expireHere = new AtomicInteger(0); - Arrays.asList(sessions).stream().filter(s -> !(s == null || s.isValid())) - .forEach(s -> expireHere.getAndIncrement()); - -// int expiredInternal = expireInternal(); -// int expired = expireHere.addAndGet(expiredInternal); - - long duration = System.currentTimeMillis() - timeNow; - if (log().isDebugEnabled()) { - log().debug(String.format("Expired %d of %d sessions in %dms.", expireHere.intValue(), sessions.length, - duration)); - } - - processingTime += duration; - } - @Override public Session createEmptySession() { return new Session(this); @@ -99,10 +117,14 @@ public Session findSession(String id) throws IOException { } } else { try { - session = Session.create(this, sessionData); + session = Session.load(this, sessionData); if (log().isDebugEnabled()) { - log().debug( - String.format(Locale.ENGLISH, "Loaded %s in %.2fms", sessionData, getDuration(start))); + if (null == session) { + log().debug(String.format("Session %s found, but has expired!", id)); + } else { + log().debug(String.format(Locale.ENGLISH, "Loaded %s in %.2fms", sessionData, + getDuration(start))); + } } } catch (ClassNotFoundException e) { log().error("Error loading session" + id, e); @@ -126,22 +148,47 @@ public final boolean commit(Session session) throws IOException { return commit(session, null); } + /** + * If one of these condition matches, the session is persisted to the store: + * + * + * @param session + * @param alternativeSiteName + * + * @return + * + * @throws IOException + */ public final boolean commit(org.apache.catalina.Session session, String alternativeSiteName) throws IOException { + session.endAccess(); + boolean saved = false; long start = System.nanoTime(); + + SessionData oldSessionData = null; Session sessionInternal = Session.class.cast(session); - session.endAccess(); + boolean sessionDirty = sessionInternal.isDirty(); + int checksum = -1; int oldChecksum = -1; - boolean sessionDirty = false; - boolean saved = false; - if (!sticky || (sessionDirty = sessionInternal.isDirty()) - || (oldChecksum = findSessionInternal(session.getId()).checksum()) != sessionInternal.checksum()) { + long secondsSinceAccess = 0; + if (!sticky || sessionDirty || (checksum = sessionInternal + .checksum()) != (oldChecksum = ((oldSessionData = findSessionInternal(session.getId())).checksum())) + || (secondsSinceAccess = oldSessionData.secondsSinceAccessed()) > sessionSaveIntervalSeconds) { SessionData sessionData = sessionInternal.serialize(alternativeSiteName); updateSession(sessionInternal.getId(), sessionData); saved = true; if (log().isDebugEnabled()) { String reason = sticky - ? (sessionDirty ? "dirty-flag was set" : String.format("checksum <> %s", oldChecksum)) + ? (sessionDirty ? "dirty-flag was set" + : (secondsSinceAccess > sessionSaveIntervalSeconds + ? "last accessed " + secondsSinceAccess + " seconds ago" + : String.format("checksum %s <> %s", oldChecksum, checksum))) : "sticky=false"; + log().debug(String.format(Locale.ENGLISH, "Saved %s (%s) in %.2fms", sessionData, reason, getDuration(start))); } @@ -161,9 +208,16 @@ public void add(org.apache.catalina.Session session) { } @Override - public void remove(org.apache.catalina.Session session, boolean update) { - super.remove(session, update); - removeInternal(session, update); + public void remove(org.apache.catalina.Session session, boolean expired) { + super.remove(session, expired); + removeInternal(session); + if (expired && log().isDebugEnabled()) { + String message = String.format(Locale.ENGLISH, + "%s has expired! Last accessed at %s, maxLifeTime: %ss, age: %s seconds", session.getId(), + new Date(session.getLastAccessedTimeInternal()), session.getMaxInactiveInterval(), + (System.currentTimeMillis() - session.getLastAccessedTimeInternal()) / 1000); + log().debug(message); + } } /** @@ -191,6 +245,10 @@ public void setSticky(boolean sticky) { this.sticky = sticky; } + public void setSessionSaveIntervalSeconds(int sessionSaveIntervalSeconds) { + this.sessionSaveIntervalSeconds = sessionSaveIntervalSeconds; + } + @Override public void load() throws ClassNotFoundException, IOException { // don't load all sessions when starting diff --git a/src/main/java/org/appng/tomcat/session/hazelcast/HazelcastSessionManager.java b/src/main/java/org/appng/tomcat/session/hazelcast/HazelcastSessionManager.java index 3b2a38a..82630ea 100644 --- a/src/main/java/org/appng/tomcat/session/hazelcast/HazelcastSessionManager.java +++ b/src/main/java/org/appng/tomcat/session/hazelcast/HazelcastSessionManager.java @@ -6,27 +6,76 @@ import java.util.Arrays; import java.util.List; import java.util.UUID; +import java.util.concurrent.atomic.AtomicInteger; import org.apache.catalina.LifecycleException; import org.apache.catalina.LifecycleState; import org.apache.juli.logging.Log; +import org.appng.tomcat.session.Session; import org.appng.tomcat.session.SessionData; import org.appng.tomcat.session.SessionManager; import org.appng.tomcat.session.Utils; +import com.hazelcast.cluster.Address; import com.hazelcast.config.ClasspathXmlConfig; +import com.hazelcast.core.EntryEvent; import com.hazelcast.core.Hazelcast; import com.hazelcast.core.HazelcastInstance; import com.hazelcast.map.IMap; +import com.hazelcast.map.listener.EntryRemovedListener; import com.hazelcast.topic.ITopic; import com.hazelcast.topic.Message; import com.hazelcast.topic.MessageListener; -public class HazelcastSessionManager extends SessionManager> - implements MessageListener { +public class HazelcastSessionManager extends SessionManager> { private final Log log = Utils.getLog(HazelcastSessionManager.class); + // Listen for sessions that have been remove from the persistent store + private class SessionRemovedListener implements EntryRemovedListener { + @Override + public void entryRemoved(EntryEvent event) { + // remove locally cached session + String sessionId = event.getOldValue().getId(); + org.apache.catalina.Session oldValue = sessions.remove(sessionId); + if (log.isDebugEnabled()) { + Address address = event.getMember().getAddress(); + if (null != oldValue) { + log.debug(String.format("%s has been removed from local cache due to removal event from %s", + sessionId, address)); + } else { + log.debug(String.format("%s was not present in local cache, received removal event from %s", + sessionId, address)); + } + } + } + } + + private class SiteReloadListener implements MessageListener { + @Override + public void onMessage(Message message) { + // clears the locally cached sessions when a SiteReloadEvent occurs + byte[] data = message.getMessageObject(); + try { + ByteArrayInputStream bais = new ByteArrayInputStream(data); + ObjectInputStream ois = new ObjectInputStream(bais); + String siteName = (String) ois.readObject(); + bais.reset(); + ObjectInputStream siteOis = Utils.getObjectInputStream(bais, siteName, getContext()); + // org.appng.api.messaging.Serializer first writes the siteName, then the event itself + siteName = (String) siteOis.readObject(); + Object event = siteOis.readObject(); + String eventType = event.getClass().getName(); + if (clearSessionsOnEvent.contains(eventType)) { + log.info(String.format("Received %s, clearing %s local sessions!", eventType, sessions.size())); + sessions.clear(); + } + } catch (Throwable t) { + log.error("Error reading event", t); + } + } + } + private String configFile = "hazelcast.xml"; private String mapName = "tomcat.sessions"; private String topicName = "appng-messaging"; @@ -45,11 +94,12 @@ protected void startInternal() throws LifecycleException { super.startInternal(); ClasspathXmlConfig config = new ClasspathXmlConfig(configFile); instance = Hazelcast.getOrCreateHazelcastInstance(config); - UUID listenerUid = getTopic().addMessageListener((MessageListener) this); + UUID listenerUid = getTopic().addMessageListener((MessageListener) new SiteReloadListener()); log.info(String.format("Attached to topic %s with UUID %s", topicName, listenerUid)); log.info(String.format("Loaded %s from %s", instance, configFile)); log.info(String.format("Sticky: %s", sticky)); setState(LifecycleState.STARTING); + getPersistentSessions().addEntryListener(new SessionRemovedListener(), true); } protected ITopic getTopic() { @@ -57,24 +107,33 @@ protected ITopic getTopic() { } @Override - public void onMessage(Message message) { - byte[] data = message.getMessageObject(); - try { - ByteArrayInputStream bais = new ByteArrayInputStream(data); - ObjectInputStream ois = new ObjectInputStream(bais); - String siteName = (String) ois.readObject(); - bais.reset(); - ObjectInputStream siteOis = Utils.getObjectInputStream(bais, siteName, getContext()); - // org.appng.api.messaging.Serializer first writes the siteName, then the event itself - siteName = (String) siteOis.readObject(); - Object event = siteOis.readObject(); - String eventType = event.getClass().getName(); - if (clearSessionsOnEvent.contains(eventType)) { - log.info(String.format("Received %s, clearing %s local sessions!", eventType, sessions.size())); - sessions.clear(); + public void processExpires() { + long timeNow = System.currentTimeMillis(); + // sufficient to iterate over the local keyset here, + // since processExpires is called on every node + AtomicInteger count = new AtomicInteger(0); + getPersistentSessions().localKeySet().forEach(k -> { + SessionData sessionData = getPersistentSessions().get(k); + try { + Session session = Session.load(this, sessionData); + if (null == session) { + // session is not valid, so manager.remove(session, true) already has been called + // which in turn will remove the session from the local cache and also from the persistent store + count.incrementAndGet(); + if (log.isTraceEnabled()) { + log.trace(String.format("%s has been removed by internal expiration", k, mapName)); + } + } + } catch (Exception e) { + log.error("Error expiring session " + k, e); } - } catch (Throwable t) { - log.error("Error reading event", t); + }); + long timeEnd = System.currentTimeMillis(); + long duration = timeEnd - timeNow; + processingTime += duration; + if (log.isDebugEnabled()) { + log.debug(String.format("Expired %s of %s sessions in %sms", count, getPersistentSessions().size(), + duration)); } } @@ -112,10 +171,10 @@ protected SessionData findSessionInternal(String id) throws IOException { } @Override - public void removeInternal(org.apache.catalina.Session session, boolean update) { + public void removeInternal(org.apache.catalina.Session session) { getPersistentSessions().remove(session.getId()); if (log.isTraceEnabled()) { - log.trace(String.format("Removed %s (update: %s)", session.getId(), update)); + log.trace(String.format("%s has been removed from '%s'", session.getId(), mapName)); } } diff --git a/src/main/java/org/appng/tomcat/session/mongo/MongoSessionManager.java b/src/main/java/org/appng/tomcat/session/mongo/MongoSessionManager.java index 40284da..9897b93 100644 --- a/src/main/java/org/appng/tomcat/session/mongo/MongoSessionManager.java +++ b/src/main/java/org/appng/tomcat/session/mongo/MongoSessionManager.java @@ -264,7 +264,7 @@ sessionQuery, getDuration(start), mongoSession.getDate(PROP_LAST_MODIFIED), } @Override - public void removeInternal(Session session, boolean update) { + public void removeInternal(Session session) { String id = session.getId(); BasicDBObject sessionQuery = sessionQuery(id); try { diff --git a/src/test/java/org/appng/tomcat/session/hazelcast/HazelcastSessionManagerIT.java b/src/test/java/org/appng/tomcat/session/hazelcast/HazelcastSessionManagerIT.java index b78eaf8..4deb41e 100644 --- a/src/test/java/org/appng/tomcat/session/hazelcast/HazelcastSessionManagerIT.java +++ b/src/test/java/org/appng/tomcat/session/hazelcast/HazelcastSessionManagerIT.java @@ -53,6 +53,27 @@ public class HazelcastSessionManagerIT { static HazelcastSessionManager manager; static StandardContext context; + @Test + public void testSessionExpired() throws Exception { + manager.setSessionSaveIntervalSeconds(2); + Session session = manager.createEmptySession(); + session.setCreationTime(System.currentTimeMillis()); + session.setMaxInactiveInterval(6); + session.setId("4711"); + session.setNew(true); + session.setValid(true); + session.setAttribute("foo", "bar"); + Assert.assertTrue(manager.commit(session)); + Thread.sleep(3000); + + Assert.assertTrue(manager.commit(session)); + Thread.sleep(7000); + + SessionData serialized = session.serialize("appng"); + Session created = Session.load(manager, serialized); + Assert.assertNull(created); + } + @Test public void test() throws Exception { Session session = createSession(); @@ -133,10 +154,11 @@ private int assertSessionChanged(Session session, int oldCheckSum, boolean isCom @Test public void testNonSticky() throws Exception { + manager.setSticky(false); Session session = createSession(); int checkSum1 = session.checksum(); Map map = modifySession(session); - int checkSum2 = assertSessionChanged(session, checkSum1, false); + int checkSum2 = assertSessionChanged(session, checkSum1, true); SessionData original = session.serialize(); int checksum3 = original.checksum(); Assert.assertEquals(checkSum2, checksum3); @@ -199,23 +221,23 @@ public void sessionCreated(HttpSessionEvent se) { s.setAttribute("metaData", new MetaData()); if (0 == i) { session = s; + Assert.assertTrue(session.isNew()); } + manager.commit(s); } - Assert.assertTrue(session.isNew()); IMap persistentSessions = manager.getPersistentSessions(); - Assert.assertTrue(session.isNew()); - Assert.assertEquals(0, persistentSessions.size()); + Assert.assertEquals(50, persistentSessions.size()); Assert.assertEquals(numSessions, manager.getActiveSessions()); manager.commit(session); - Assert.assertEquals(1, persistentSessions.size()); + Assert.assertEquals(50, persistentSessions.size()); Assert.assertEquals(numSessions, manager.getActiveSessions()); Assert.assertFalse(session.isNew()); TimeUnit.SECONDS.sleep(2); manager.processExpires(); Assert.assertEquals(25L, manager.getExpiredSessions()); - Assert.assertEquals(0, persistentSessions.size()); + Assert.assertEquals(25, persistentSessions.size()); Assert.assertNull(manager.findSession(session.getId())); @@ -239,6 +261,7 @@ public void sessionCreated(HttpSessionEvent se) { } Thread.sleep(100); Assert.assertEquals(0, manager.getActiveSessions()); + } @BeforeClass diff --git a/src/test/resources/log4j.properties b/src/test/resources/log4j.properties index 72b26cb..c9454bc 100644 --- a/src/test/resources/log4j.properties +++ b/src/test/resources/log4j.properties @@ -5,4 +5,6 @@ log4j.appender.stdout = org.apache.log4j.ConsoleAppender log4j.appender.stdout.layout = org.apache.log4j.EnhancedPatternLayout log4j.appender.stdout.layout.ConversionPattern = %d{ISO8601} %-5p [%t] %-32c{1.}: %m%n -log4j.category.org.mongodb = info \ No newline at end of file +log4j.category.org.mongodb = info +log4j.category.org.appng.tomcat.session=info +log4j.category.com.hazelcast.spi.impl=info