Ok , So now we started node 1 , waited until it was up and running and only
then we started node2.
There are no warnings \ errors on the log files.
Only problem is that our session's are not being replicated.
here are the logs of the catalina:
Node1:
Dec 17, 2013 10:52:21 AM org.apache.catalina.core.AprLifecycleListener init
INFO: The APR based Apache Tomcat Native library which allows optimal
performance in production environments was not found on the
java.library.path: /usr/java/packages/lib/amd64:/usr/lib/jni:/lib:/usr/lib
Dec 17, 2013 10:52:21 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-bio-8080"]
Dec 17, 2013 10:52:21 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["ajp-bio-8009"]
Dec 17, 2013 10:52:21 AM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 789 ms
Dec 17, 2013 10:52:21 AM org.apache.catalina.core.StandardService
startInternal
INFO: Starting service Catalina
Dec 17, 2013 10:52:21 AM org.apache.catalina.core.StandardEngine
startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.47
Dec 17, 2013 10:52:21 AM org.apache.catalina.ha.tcp.SimpleTcpCluster
startInternal
INFO: Cluster is about to start
Dec 17, 2013 10:52:21 AM org.apache.catalina.tribes.transport.ReceiverBase
bind
INFO: Receiver Server Socket bound to:/127.0.1.1:5000
Dec 17, 2013 10:52:21 AM
org.apache.catalina.tribes.membership.McastServiceImpl setupSocket
INFO: Setting cluster mcast soTimeout to 500
Dec 17, 2013 10:52:21 AM
org.apache.catalina.tribes.membership.McastServiceImpl waitForMembers
INFO: Sleeping for 1000 milliseconds to establish cluster membership, start
level:4
Dec 17, 2013 10:52:22 AM
org.apache.catalina.tribes.membership.McastServiceImpl waitForMembers
INFO: Done sleeping, membership established, start level:4
Dec 17, 2013 10:52:22 AM
org.apache.catalina.tribes.membership.McastServiceImpl waitForMembers
INFO: Sleeping for 1000 milliseconds to establish cluster membership, start
level:8
Dec 17, 2013 10:52:23 AM
org.apache.catalina.tribes.membership.McastServiceImpl waitForMembers
INFO: Done sleeping, membership established, start level:8
Dec 17, 2013 10:52:23 AM org.apache.catalina.ha.deploy.FarmWarDeployer start
INFO: Cluster FarmWarDeployer started.
Dec 17, 2013 10:52:23 AM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive
/usr/local/tomcat7/apache-tomcat-7.0.47/webapps/HATest.war
Dec 17, 2013 10:52:24 AM
org.apache.catalina.tribes.tipis.AbstractReplicatedMap init
INFO: Initializing AbstractReplicatedMap with context name:/HATest-map
Dec 17, 2013 10:52:24 AM org.apache.catalina.startup.HostConfig
deployDirectory
INFO: Deploying web application directory
/usr/local/tomcat7/apache-tomcat-7.0.47/webapps/docs
Dec 17, 2013 10:52:24 AM org.apache.catalina.startup.HostConfig
deployDirectory
INFO: Deploying web application directory
/usr/local/tomcat7/apache-tomcat-7.0.47/webapps/host-manager
Dec 17, 2013 10:52:24 AM org.apache.catalina.startup.HostConfig
deployDirectory
INFO: Deploying web application directory
/usr/local/tomcat7/apache-tomcat-7.0.47/webapps/ROOT
Dec 17, 2013 10:52:24 AM org.apache.catalina.startup.HostConfig
deployDirectory
INFO: Deploying web application directory
/usr/local/tomcat7/apache-tomcat-7.0.47/webapps/examples
Dec 17, 2013 10:52:24 AM org.apache.catalina.startup.HostConfig
deployDirectory
INFO: Deploying web application directory
/usr/local/tomcat7/apache-tomcat-7.0.47/webapps/manager
Dec 17, 2013 10:52:25 AM
org.apache.catalina.tribes.tipis.AbstractReplicatedMap init
INFO: Initializing AbstractReplicatedMap with context name:/manager-map
Dec 17, 2013 10:52:25 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-bio-8080"]
Dec 17, 2013 10:52:25 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["ajp-bio-8009"]
Dec 17, 2013 10:52:25 AM org.apache.catalina.startup.Catalina start
INFO: Server startup in 3592 ms
Dec 17, 2013 10:52:42 AM 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=1016, securePort=-1, UDP Port=-1, id={12
109 58 47 47 -29 65 29 -113 -10 7 24 97 -113 -24 -96 }, payload={},
command={}, domain={}, ]
Dec 17, 2013 10:52:42 AM 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 17, 2013 10:52:43 AM
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.08 MB/sec (total)
TxSpeed:0.08 MB/sec (application)
Error Msg:0
Rx Msg:2 messages
Rx Speed:0.00 MB/sec (since 1st msg)
Received:0.00 MB]
Node 2:
Dec 17, 2013 10:52:40 AM org.apache.catalina.core.AprLifecycleListener init
INFO: The APR based Apache Tomcat Native library which allows optimal
performance in production environments was not found on the
java.library.path: /usr/java/packages/lib/amd64:/usr/lib/jni:/lib:/usr/lib
Dec 17, 2013 10:52:41 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-bio-8080"]
Dec 17, 2013 10:52:41 AM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["ajp-bio-8009"]
Dec 17, 2013 10:52:41 AM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 785 ms
Dec 17, 2013 10:52:41 AM org.apache.catalina.core.StandardService
startInternal
INFO: Starting service Catalina
Dec 17, 2013 10:52:41 AM org.apache.catalina.core.StandardEngine
startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.47
Dec 17, 2013 10:52:41 AM org.apache.catalina.ha.tcp.SimpleTcpCluster
startInternal
INFO: Cluster is about to start
Dec 17, 2013 10:52:41 AM org.apache.catalina.tribes.transport.ReceiverBase
bind
INFO: Receiver Server Socket bound to:/127.0.1.1:5000
Dec 17, 2013 10:52:41 AM
org.apache.catalina.tribes.membership.McastServiceImpl setupSocket
INFO: Setting cluster mcast soTimeout to 500
Dec 17, 2013 10:52:41 AM
org.apache.catalina.tribes.membership.McastServiceImpl waitForMembers
INFO: Sleeping for 1000 milliseconds to establish cluster membership, start
level:4
Dec 17, 2013 10:52:41 AM 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=20048, securePort=-1, UDP Port=-1,
id={-75 -112 -71 -42 50 -11 66 22 -119 -76 81 72 -52 -92 65 110 },
payload={}, command={}, domain={}, ]
Dec 17, 2013 10:52:41 AM 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 17, 2013 10:52:42 AM
org.apache.catalina.tribes.membership.McastServiceImpl waitForMembers
INFO: Done sleeping, membership established, start level:4
Dec 17, 2013 10:52:42 AM
org.apache.catalina.tribes.membership.McastServiceImpl waitForMembers
INFO: Sleeping for 1000 milliseconds to establish cluster membership, start
level:8
Dec 17, 2013 10:52:43 AM
org.apache.catalina.tribes.membership.McastServiceImpl waitForMembers
INFO: Done sleeping, membership established, start level:8
Dec 17, 2013 10:52:43 AM org.apache.catalina.ha.deploy.FarmWarDeployer start
INFO: Cluster FarmWarDeployer started.
Dec 17, 2013 10:52:43 AM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive
/usr/local/tomcat7/apache-tomcat-7.0.47/webapps/HATest.war
Dec 17, 2013 10:52:43 AM
org.apache.catalina.tribes.tipis.AbstractReplicatedMap init
INFO: Initializing AbstractReplicatedMap with context name:/HATest-map
Dec 17, 2013 10:52:43 AM
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.08 MB/sec (total)
TxSpeed:0.08 MB/sec (application)
Error Msg:0
Rx Msg:2 messages
Rx Speed:0.00 MB/sec (since 1st msg)
Received:0.00 MB]
Dec 17, 2013 10:52:43 AM org.apache.catalina.startup.HostConfig
deployDirectory
INFO: Deploying web application directory
/usr/local/tomcat7/apache-tomcat-7.0.47/webapps/docs
Dec 17, 2013 10:52:43 AM org.apache.catalina.startup.HostConfig
deployDirectory
INFO: Deploying web application directory
/usr/local/tomcat7/apache-tomcat-7.0.47/webapps/host-manager
Dec 17, 2013 10:52:44 AM org.apache.catalina.startup.HostConfig
deployDirectory
INFO: Deploying web application directory
/usr/local/tomcat7/apache-tomcat-7.0.47/webapps/ROOT
Dec 17, 2013 10:52:44 AM org.apache.catalina.startup.HostConfig
deployDirectory
INFO: Deploying web application directory
/usr/local/tomcat7/apache-tomcat-7.0.47/webapps/examples
Dec 17, 2013 10:52:44 AM org.apache.catalina.startup.HostConfig
deployDirectory
INFO: Deploying web application directory
/usr/local/tomcat7/apache-tomcat-7.0.47/webapps/manager
Dec 17, 2013 10:52:44 AM
org.apache.catalina.tribes.tipis.AbstractReplicatedMap init
INFO: Initializing AbstractReplicatedMap with context name:/manager-map
Dec 17, 2013 10:52:44 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-bio-8080"]
Dec 17, 2013 10:52:44 AM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["ajp-bio-8009"]
Dec 17, 2013 10:52:44 AM org.apache.catalina.startup.Catalina start
INFO: Server startup in 3571 ms
We have 3 sessions currently: one on node-1 and 2 on node-2 but there are
only primary sessions on each (3) and not backup sessions at all. what
could be the problem?
On Tue, Dec 17, 2013 at 10:25 AM, Keiichi Fujino <kfuj...@apache.org> wrote:
> 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
>
