Project: Tomcat
Bug 53513 Race condition / out of order operation in session replication at node startup
Reported: 2012-07-05 21:56:22 | Status: resolved fixed

My configuration: 2 nodes running Tomcat 7.0.26 Using a custom session manager, which extends the DeltaManager My startInternal() method first calls super.startInternal(), then performs a few additional initializations. I reviewed the code of DeltaManager.startInternal(), and it calls getAllClusterSessions() which in turn calls waitForSendAllSessions(), which requires either getStateTransfered() to return true, or a timeout. So by this, I should be able to trust that as the second node starts, the initial sync up of all session data from the first node has completed prior to the startInternal() method exiting (and thus prior to my initializations). This is, however, not the case! I can confirm this by repeatedly logging the value of findSessions().length during my inializations, and see that number going up! There appears to be a race condition between the processing of the message containing the actual session data & the "transfer complete" message. After tracing this through a little further, I see the stateTransfered is set to true in the handleALL_SESSION_TRANSFERCOMPLETE() callback method. And that callback is being called PRIOR to the session data itself even being received! Here is the debug logging output (slightly scrubbed) which shows this out of order messaging: Jul 5, 2012 4:20:41 PM org.apache.catalina.ha.session.DeltaManager getAllClusterSessions INFO: Manager [wwwtest#], requesting session state from org.apache.catalina.tribes.membership.MemberImpl[...]. This operation will timeout if no session state has been received within 60 seconds. Jul 5, 2012 4:20:41 PM org.apache.catalina.ha.session.DeltaManager messageReceived FINE: Manager [wwwtest#]: Received SessionMessage of type=(SESSION-STATE-TRANSFERED) from [org.apache.catalina.tribes.membership.MemberImpl[...] Jul 5, 2012 4:20:41 PM org.apache.catalina.ha.session.DeltaManager handleALL_SESSION_TRANSFERCOMPLETE FINE: Manager [wwwtest#] received from node [[B@6789b939:4,000] session state transfered. Jul 5, 2012 4:20:41 PM org.apache.catalina.ha.session.DeltaManager messageReceived FINE: Manager [wwwtest#]: Received SessionMessage of type=(ALL-SESSION-DATA) from [org.apache.catalina.tribes.membership.MemberImpl[...] Jul 5, 2012 4:20:41 PM org.apache.catalina.ha.session.DeltaManager handleALL_SESSION_DATA FINE: Manager [wwwtest#]: received session state data

Files changed in fix:
java/org/apache/catalina/ha/tcp/SimpleTcpCluster.java