DeltaManager starts session sync phase by sending a SESSION-GET-ALL message
at startup.
DeltaManager that has received the SESSION-GET-ALL message sends all
session data by sending a ALL-SESSION-DATA message.
Then sends a SESSION-STATE-TRANSFERED message in order to notify the
transmission completion.
DeltaManager that has received the SESSION-STATE-TRANSFERED message
completes session sync phase.
According to this log,
> Dec 16, 2013 6:43:29 PM org.apache.catalina.ha.session.DeltaManager
> waitForSendAllSessions
> SEVERE: Manager [/HATest]: No session state send at 12/16/13 6:42 PM
> received, timing out after 60,102 ms.
>
This log means that time-out occurred in session sync phase. (Default 60
seconds)
and
> Dec 16, 2013 6:43:29 PM org.apache.catalina.ha.session.DeltaManager
> getAllClusterSessions
> WARNING: Manager [/HATest]: Drop message SESSION-GET-ALL inside
> GET_ALL_SESSIONS sync phase start date 12/16/13 6:42 PM message date 1/1/70
> 2:00 AM
>
This log means that SESSION-GET-ALL message that received during session
sync phase is dropped.
Thus, It seems that two nodes were started at the same time.
If SESSION-GET-ALL message is dropped, SESSION-STATE-TRANSFERED message can
not be received.
As a result, will be time-out in session sync phase.
You should start Tomcat in proper order (rather than simultaneously).
Another problem.
In warning log, time stamp of the SESSION-GET-ALL messages that were
dropped has become to 1/1/70.
This is just a trivial bug.
I will fix this later.
That way, the correct time stamp will be output.
> Dec 16, 2013 6:43:29 PM org.apache.catalina.startup.HostConfig
> deployDirectory
> INFO: Deploying web application directory
> /usr/local/tomcat7/apache-tomcat-7.0.47/webapps/docs
> Dec 16, 2013 6:43:29 PM org.apache.catalina.startup.HostConfig
> deployDirectory
> INFO: Deploying web application directory
> /usr/local/tomcat7/apache-tomcat-7.0.47/webapps/host-manager
> Dec 16, 2013 6:43:29 PM org.apache.catalina.startup.HostConfig
> deployDirectory
> INFO: Deploying web application directory
> /usr/local/tomcat7/apache-tomcat-7.0.47/webapps/ROOT
> Dec 16, 2013 6:43:29 PM org.apache.catalina.startup.HostConfig
> deployDirectory
> INFO: Deploying web application directory
> /usr/local/tomcat7/apache-tomcat-7.0.47/webapps/examples
> Dec 16, 2013 6:43:30 PM org.apache.catalina.startup.HostConfig
> deployDirectory
> INFO: Deploying web application directory
> /usr/local/tomcat7/apache-tomcat-7.0.47/webapps/manager
> Dec 16, 2013 6:43:30 PM org.apache.catalina.ha.session.DeltaManager
> startInternal
> INFO: Register manager /manager to cluster element Host with name localhost
> Dec 16, 2013 6:43:30 PM org.apache.catalina.ha.session.DeltaManager
> startInternal
> INFO: Starting clustering manager at /manager
> Dec 16, 2013 6:43:30 PM org.apache.catalina.ha.session.DeltaManager
> getAllClusterSessions
> INFO: Manager [/manager], requesting session state from
> org.apache.catalina.tribes.membership.MemberImpl[tcp://{127, 0, 1,
> 1}:5000,{127, 0, 1, 1},5000, alive=65057, securePort=-1, UDP Port=-1,
> id={-90 41 -113 110 96 -50 78 -88 -79 -103 1 61 -60 -125 75 44 },
> payload={}, command={}, domain={}, ]. This operation will timeout if no
> session state has been received within 60 seconds.
> Dec 16, 2013 6:44:16 PM
> org.apache.catalina.tribes.group.interceptors.TcpFailureDetector
> memberDisappeared
> INFO: Verification complete. Member
> disappeared[org.apache.catalina.tribes.membership.MemberImpl[tcp://{127, 0,
> 1, 1}:5000,{127, 0, 1, 1},5000, alive=112037, securePort=-1, UDP Port=-1,
> id={-90 41 -113 110 96 -50 78 -88 -79 -103 1 61 -60 -125 75 44 },
> payload={}, command={66 65 66 89 45 65 76 69 88 ...(9)}, domain={}, ]]
> Dec 16, 2013 6:44:16 PM org.apache.catalina.ha.tcp.SimpleTcpCluster
> memberDisappeared
> INFO: Received member
> disappeared:org.apache.catalina.tribes.membership.MemberImpl[tcp://{127, 0,
> 1, 1}:5000,{127, 0, 1, 1},5000, alive=112037, securePort=-1, UDP Port=-1,
> id={-90 41 -113 110 96 -50 78 -88 -79 -103 1 61 -60 -125 75 44 },
> payload={}, command={66 65 66 89 45 65 76 69 88 ...(9)}, domain={}, ]
> Dec 16, 2013 6:44:22 PM org.apache.catalina.ha.tcp.SimpleTcpCluster
> memberAdded
> INFO: Replication member
> added:org.apache.catalina.tribes.membership.MemberImpl[tcp://{127, 0, 1,
> 1}:5000,{127, 0, 1, 1},5000, alive=1014, securePort=-1, UDP Port=-1, id={75
> 3 86 -1 25 78 67 111 -125 -65 74 58 79 -20 93 16 }, payload={}, command={},
> domain={}, ]
> Dec 16, 2013 6:44:30 PM org.apache.catalina.ha.session.DeltaManager
> waitForSendAllSessions
> SEVERE: Manager [/manager]: No session state send at 12/16/13 6:43 PM
> received, timing out after 60,081 ms.
> Dec 16, 2013 6:44:30 PM org.apache.catalina.ha.session.DeltaManager
> getAllClusterSessions
> WARNING: Manager [/manager]: Drop message SESSION-GET-ALL inside
> GET_ALL_SESSIONS sync phase start date 12/16/13 6:43 PM message date 1/1/70
> 2:00 AM
> Dec 16, 2013 6:44:30 PM org.apache.coyote.AbstractProtocol start
> INFO: Starting ProtocolHandler ["http-bio-8080"]
> Dec 16, 2013 6:44:30 PM org.apache.coyote.AbstractProtocol start
> INFO: Starting ProtocolHandler ["ajp-bio-8009"]
> Dec 16, 2013 6:44:30 PM org.apache.catalina.startup.Catalina start
> INFO: Server startup in 123619 ms
>
>
>
>
>
> *When we try to configure the Backup manager (which is my goal actually)
> with the same server.xml only with backup manager tag:*
> <Manager className="org.apache.catalina.ha.session.BackupManager"
> expireSessionsOnShutdown="false"
> notifyListenersOnReplication="true"
> mapSendOptions="6"/>
>
>
> *We get the following log (again, no replication):*
>
>
> INFO: Cluster is about to start
> Dec 16, 2013 6:56:40 PM org.apache.catalina.tribes.transport.ReceiverBase
> bind
> INFO: Receiver Server Socket bound to:/127.0.1.1:5000
> Dec 16, 2013 6:56:40 PM
> org.apache.catalina.tribes.membership.McastServiceImpl setupSocket
> INFO: Setting cluster mcast soTimeout to 500
> Dec 16, 2013 6:56:40 PM
> org.apache.catalina.tribes.membership.McastServiceImpl waitForMembers
> INFO: Sleeping for 1000 milliseconds to establish cluster membership, start
> level:4
> Dec 16, 2013 6:56:40 PM org.apache.catalina.ha.tcp.SimpleTcpCluster
> memberAdded
> INFO: Replication member
> added:org.apache.catalina.tribes.membership.MemberImpl[tcp://{127, 0, 1,
> 1}:5000,{127, 0, 1, 1},5000, alive=23027, securePort=-1, UDP Port=-1,
> id={52 -40 0 -117 -60 82 71 -42 -110 21 -91 -16 88 -96 -46 -113 },
> payload={}, command={}, domain={}, ]
> Dec 16, 2013 6:56:41 PM org.apache.catalina.tribes.io.BufferPool
> getBufferPool
> INFO: Created a buffer pool with max size:104857600 bytes of
> type:org.apache.catalina.tribes.io.BufferPool15Impl
> Dec 16, 2013 6:56:41 PM
> org.apache.catalina.tribes.membership.McastServiceImpl waitForMembers
> INFO: Done sleeping, membership established, start level:4
> Dec 16, 2013 6:56:41 PM
> org.apache.catalina.tribes.membership.McastServiceImpl waitForMembers
> INFO: Sleeping for 1000 milliseconds to establish cluster membership, start
> level:8
> Dec 16, 2013 6:56:42 PM
> org.apache.catalina.tribes.membership.McastServiceImpl waitForMembers
> INFO: Done sleeping, membership established, start level:8
> Dec 16, 2013 6:56:42 PM org.apache.catalina.ha.deploy.FarmWarDeployer start
> INFO: Cluster FarmWarDeployer started.
> Dec 16, 2013 6:56:42 PM org.apache.catalina.startup.HostConfig deployWAR
> INFO: Deploying web application archive
> /usr/local/tomcat7/apache-tomcat-7.0.47/webapps/HATest.war
> Dec 16, 2013 6:56:43 PM
> org.apache.catalina.tribes.tipis.AbstractReplicatedMap init
> INFO: Initializing AbstractReplicatedMap with context name:/HATest-map
> Dec 16, 2013 6:56:43 PM
> org.apache.catalina.tribes.group.interceptors.ThroughputInterceptor report
> INFO: ThroughputInterceptor Report[
> Tx Msg:1 messages
> Sent:0.00 MB (total)
> Sent:0.00 MB (application)
> Time:0.01 seconds
> Tx Speed:0.09 MB/sec (total)
> TxSpeed:0.09 MB/sec (application)
> Error Msg:0
> Rx Msg:2 messages
> Rx Speed:0.00 MB/sec (since 1st msg)
> Received:0.00 MB]
>
> Dec 16, 2013 6:56:43 PM org.apache.catalina.startup.HostConfig
> deployDirectory
> INFO: Deploying web application directory
> /usr/local/tomcat7/apache-tomcat-7.0.47/webapps/docs
> Dec 16, 2013 6:56:43 PM org.apache.catalina.startup.HostConfig
> deployDirectory
> INFO: Deploying web application directory
> /usr/local/tomcat7/apache-tomcat-7.0.47/webapps/host-manager
> Dec 16, 2013 6:56:43 PM org.apache.catalina.startup.HostConfig
> deployDirectory
> INFO: Deploying web application directory
> /usr/local/tomcat7/apache-tomcat-7.0.47/webapps/ROOT
> Dec 16, 2013 6:56:43 PM org.apache.catalina.startup.HostConfig
> deployDirectory
> INFO: Deploying web application directory
> /usr/local/tomcat7/apache-tomcat-7.0.47/webapps/examples
> Dec 16, 2013 6:56:44 PM org.apache.catalina.startup.HostConfig
> deployDirectory
> INFO: Deploying web application directory
> /usr/local/tomcat7/apache-tomcat-7.0.47/webapps/manager
> Dec 16, 2013 6:56:44 PM
> org.apache.catalina.tribes.tipis.AbstractReplicatedMap init
> INFO: Initializing AbstractReplicatedMap with context name:/manager-map
> Dec 16, 2013 6:56:44 PM org.apache.coyote.AbstractProtocol start
> INFO: Starting ProtocolHandler ["http-bio-8080"]
> Dec 16, 2013 6:56:44 PM org.apache.coyote.AbstractProtocol start
> INFO: Starting ProtocolHandler ["ajp-bio-8009"]
> Dec 16, 2013 6:56:44 PM org.apache.catalina.startup.Catalina start
> INFO: Server startup in 3535 ms
>
>
>
>
>
>
> *It appears there are no severe errors on the log file with the backup
> manager setup, but still we got no replication going.*
> *Of course we added the *<distributable/>
> *tag to both our web.xml of the tomcats AND for the WAR's web.xml as well.*
>
>
> *Any ideas why this is happening? *
>
> Regards and many thanks,
>
> NGT.
>
> --
> Keiichi.Fujino
