Tomcat Hazelcast Session Store Session Attributes Vanishing

Question

I am trying to setup a Tomcat cluster on AWS and since AWS does not support IP multicasting, one of the option is tomcat clustering using DB

That is well understood, however, due to performance penalties related to DB calls, I am currently considering Hazelcast as the session store. The current Hazelcast filter approach does not work out for me as there are other filters on the web app and they are somewhat interfering and a better and cleaner approach would be to configure the PersistenceManager with a custom store implementation and configure the same on the tomcat/conf context.xml, the configuration section is provided below:

   <Manager className="org.apache.catalina.session.PersistentManager"
         distributable="true"
         maxActiveSessions="-1"
         maxIdleBackup="2"
         maxIdleSwap="5"
         processingTime="1000"
         saveOnRestart="true"
         maxInactiveInterval="1200">

         <Store className="com.hm.vigil.platform.session.HC_SessionStore"/>

</Manager>

The sessions are being saved in the Hazelcast instance and the trace from tomcat is below:

---------------------------------------------------------------------------------------
HC_SessionStore == Saving Session ID == C19A496F2BB9E6A4A55E70865261FC9F SESSION == StandardSession[
C19A496F2BB9E6A4A55E70865261FC9F]
SESSION ATTRIBUTE :: USER_IDENTIFIER :: 50
SESSION ATTRIBUTE :: APPLICATION_IDENTIFIER :: APPLICATION_1
SESSION ATTRIBUTE :: USER_EMAIL :: [email protected]
SESSION ATTRIBUTE :: USER_ROLES :: [PLATFORM_ADMIN, CLIENT_ADMIN, PEN_TESTER, USER]
SESSION ATTRIBUTE :: CLIENT_IDENTIFIER :: 1
---------------------------------------------------------------------------------------
03-Nov-2015 15:12:02.562 FINE [ContainerBackgroundProcessor[StandardEngine[Catalina]]] org.apache.ca
talina.session.PersistentManagerBase.processExpires End expire sessions PersistentManager processing
Time 75 expired sessions: 0
03-Nov-2015 15:12:02.563 FINE [ContainerBackgroundProcessor[StandardEngine[Catalina]]] org.apache.ca
talina.session.PersistentManagerBase.processExpires Start expire sessions PersistentManager at 14465
43722563 sessioncount 0
03-Nov-2015 15:12:02.577 FINE [ContainerBackgroundProcessor[StandardEngine[Catalina]]] org.apache.ca
talina.session.PersistentManagerBase.processExpires End expire sessions PersistentManager processing
Time 14 expired sessions: 0

The above trace if from the 'save' method as overridden by the store implementation, the code is provided below:

@Override
    public void save(Session session) throws IOException {

        //System.out.println("HC_SessionStore == Saving Session ID == "+session.getId()+" SESSION == "+session);

        try{

            String sessionId=session.getId();

            ByteArrayOutputStream baos=new ByteArrayOutputStream();
            ObjectOutputStream oos=new ObjectOutputStream(baos);

            oos.writeObject(session);
            oos.close();

            byte[] serializedSession=baos.toByteArray();
            sessionStore.put(sessionId,serializedSession);

            sessionCounter++;

            System.out.println("---------------------------------------------------------------------------------------");
            System.out.println("HC_SessionStore == Saving Session ID == "+sessionId+" SESSION == "+session);
            Enumeration<String> attributeNames=((StandardSession)session).getAttributeNames();
            while(attributeNames.hasMoreElements()){

                String attributeName=attributeNames.nextElement();
                System.out.println("SESSION ATTRIBUTE :: "+attributeName+" :: "+((StandardSession)session).getAttribute(attributeName));

            }//while closing
            System.out.println("---------------------------------------------------------------------------------------");

        }catch(Exception e){throw new IOException(e);}

    }//save closing

Where the 'sessionStore' is a Hazelcast distributed Map.

The corresponding 'load' method of the store is as follows:

@Override
    public Session load(String sessionId) throws ClassNotFoundException, IOException {

        Session session=null;

        try{

            byte[] serializedSession=(byte[])sessionStore.get(sessionId);
            ObjectInputStream ois=new ObjectInputStream(new ByteArrayInputStream(serializedSession));

            //Read the saved session from serialized state
            //StandardSession session_=new StandardSession(manager);
            StandardSession session_=(StandardSession)ois.readObject();
            session_.setManager(manager);
            ois.close();

            //Initialize the transient properties of the session
            ois=new ObjectInputStream(new ByteArrayInputStream(serializedSession));
            session_.readObjectData(ois);
            session=session_;
            ois.close();

            System.out.println("===========================================================");
            System.out.println("HC_SessionStore == Loading Session ID == "+sessionId+" SESSION == "+session);
            Enumeration<String> attributeNames=session_.getAttributeNames();
            while(attributeNames.hasMoreElements()){

                String attributeName=attributeNames.nextElement();
                System.out.println("SESSION ATTRIBUTE :: "+attributeName+" :: "+session_.getAttribute(attributeName));

            }//while closing
            System.out.println("===========================================================");

        }catch(Exception e){throw new IOException(e);}

        return session;

    }//load closing

Now, one of the most intriguing thing is that while the 'store' method gets called at the default interval of 60 seconds, the 'load' method is never called with the net impact that any session attributes that are saved is lost after a while, which is most unusual. Technically any new session attributes that are bound to the session will be saved in the Hazelcast once the 'save' method is called and the manager is configured to swap out every 5 seconds.

However, the session attribute is lost (the new one), the old ones are still there. But whatever it is the 'load' method is not called (at least I don't see the trace).

Some help on this will be really appreciated.

strange. ofc you would've done this but still to confirm - did you put some print statements / debug points to see if load() is ever hit ? — Dinesh
Yes, there are print statements, in 'load' as in save, please refer the above code, it also prints the attributes bound to the session, thanks — Ironluca
I saw the code. I was specifically pointing to debug statements right after the load() ( which I don't see here). Since readObject is a blocking call. — Dinesh
You can also attach a MapListener to your sessionStore map to see the entries getting evicted / deleted . ( This is to debug your problem of session attribute getting lost. ) With map listener you can actually see what got added and updated. — Dinesh
Dinesh, in a way that was useful in diagonizing the problem, so I upped it, I shall post the actual problem and the solution — Ironluca

Ironluca Ironluca · Accepted Answer · 2015-11-16T12:06:48

Hope this helps someone, the problem is actually in the following code sections:

public void save(Session session) throws IOException method:

        String sessionId=session.getId();

        ByteArrayOutputStream baos=new ByteArrayOutputStream();
        ObjectOutputStream oos=new ObjectOutputStream(baos);

        oos.writeObject(session);
        oos.close();

        byte[] serializedSession=baos.toByteArray();
        sessionStore.put(sessionId,serializedSession);

public Session load(String sessionId) throws ClassNotFoundException, IOException method:

        byte[] serializedSession=(byte[])sessionStore.get(sessionId);
        ObjectInputStream ois=new ObjectInputStream(new ByteArrayInputStream(serializedSession));

        //Read the saved session from serialized state
        //StandardSession session_=new StandardSession(manager);
        StandardSession session_=(StandardSession)ois.readObject();
        session_.setManager(manager);
        ois.close();

        //Initialize the transient properties of the session
        ois=new ObjectInputStream(new ByteArrayInputStream(serializedSession));
        session_.readObjectData(ois);
        session=session_;
        ois.close();

If you notice, the session is summarily serialized and saved to the Hazelcast, that is not a problem by itself.

Now if we look at the Tomcat code for StandardSession, we see that it contains a number of transient properties that will not be serialized. So during deserialization these properties must be given values, which is done in the 'load' method, however, it is done wrongly, first it deserializes the session from the ObjectInputStream 'readObjectData' method to initialize the transient properties. In the StandardSession, 'readObjectData' calls 'doReadObject' a protected method to reinitialize the transient properties, which in turn expects that the object input stream provided is a series of objects. In our case, however, it is the entire serialized object and not the series of objects that it expects.

In fact, after enabling fine level logging on Tomcat only this exception is seen, not otherwise.

The workaround is simple, StandardSession has a method 'writeObjectData' method, which internally calls a protected method 'doWriteObject', which writes the session state in a series of objects to the output stream, reading this serialized bytes solves the problem.

Tomcat Hazelcast Session Store Session Attributes Vanishing

1 Answers