Geronimo cluster (Tomcat Version)cannot continue the HttpSession when current
node is down.
--------------------------------------------------------------------------------------------
Key: GERONIMO-2577
URL: http://issues.apache.org/jira/browse/GERONIMO-2577
Project: Geronimo
Issue Type: Bug
Security Level: public (Regular issues)
Components: Clustering, Tomcat
Affects Versions: 1.1.1, 1.1
Environment: JDK - Sun java version "1_5_0_09"(32bit)
OS- Red Hat Enterprise Linux ES4 update4(32bit)
Http Server - Apache 2.0.59 +mod_jk 1.2.19
Reporter: Kaoru Matsumura
We run Geronimo cluster with three nodes.
In our environment, with DeltaManager set for replication module, we found that
the last node cound not continue the processes when the other nodes is
intentionally halted in order.
We recognize Tomcat 5.5.15 is OK with the same configuration and operations.
Test Application
================
The Web application program, which was used for the test, simply reads the
number of access count, and then write the count to HttpSession object.
Configuration　Files
==================
We refer http://cwiki.apache.org/GMOxDOC11/clustering-sample-application.html
* config.xml
We add the following parameters to the standard configuration.
<gbean name="TomcatEngine">
<attribute name="initParams">name=Geronimo
jvmRoute=nodeA</attribute>
</gbean>
Operations
===============
1 Have browser access to Test Application , and reload several times.(*1)
HttpSession object is created on the nodeA.
2 And then, We kill the process of geronimo on the nodeA with $kill -9
<Process ID>.(*2)
3 Reload the browser at one time. The node changes to nodeB.(*3)
4 Reload the browser several times.(*4)
5 And then, We kill the process of geronimo on the nodeB with $kill -9
<Process ID>.(*5)
6 Reload the browser at one time.(And then, We expect that the process
continues at the nodeC.)
But the HttpSessionID of the HttpSession object is changed to another ID and
the counter value is back to 1.(*6)
As a result, the geronimo cluster cannot continue the process.
For avoidance
===============
When replication module is SimpleTcpReplicationManager, the geronimo cluster
can continue the process.
Debug levels logs
==================
(*1)
nodeA
----------
20:06:17,736 DEBUG [CoyoteAdapter] Requested cookie session id is
7160C8614D20687D3548E8488AB65AC3.nodeA
20:06:17,736 DEBUG [JvmRouteBinderValve] Found Cluster DeltaManager [EMAIL
PROTECTED] at /ClusterCheck
20:06:17,736 DEBUG [JvmRouteBinderValve] Turnover Check time 0 msec
20:06:17,737 DEBUG [MsgContext] COMMIT
20:06:17,737 DEBUG [JkInputStream] COMMIT sending headers [EMAIL PROTECTED] ===
MimeHeaders ===
20:06:17,737 DEBUG [MsgContext] CLOSE
20:06:17,738 DEBUG [REQ_TIME] Time pre=0/ service=2 242 /ClusterCheck/counter
20:06:17,738 DEBUG [ReplicationValve] Invoking replication request on
/ClusterCheck/counter
20:06:17,738 DEBUG [DeltaManager] Manager [/ClusterCheck]: create session
message [7160C8614D20687D3548E8488AB65AC3.nodeA] delta request.
20:06:17,757 DEBUG [McastService] Mcast receive ping from member
org.apache.catalina.cluster.mcast.McastMember[tcp://192.168.1.3:4001,catalina,192.168.1.3,4001,
alive=58960]
-----------
nodeC
-----------
20:06:17,655 DEBUG [SimpleTcpCluster] Assuming clocks are synched: Replication
for 7160C8614D20687D3548E8488AB65AC3.nodeA-1162811177738 took=-83 ms.
20:06:17,655 DEBUG [DeltaManager] Manager [/ClusterCheck]: Received
SessionMessage of type=(SESSION-DELTA) from
[org.apache.catalina.cluster.mcast.McastMember[tcp://192.168.1.1:4001,catalina,192.168.1.1,4001,
alive=130441]]
20:06:17,655 DEBUG [DeltaManager] Manager [/ClusterCheck]: received session
[7160C8614D20687D3548E8488AB65AC3.nodeA] delta.
-----------
(*2)
nodeB (same as nodeC)
-----------
20:06:39,817 INFO [SimpleTcpCluster] Received member
disappeared:org.apache.catalina.cluster.mcast.McastMember[tcp://192.168.1.1:4001,catalina,192.168.1.1,4001,
alive=149288]
20:06:39,818 DEBUG [MapperListener] Handle
geronimo:type=IDataSender,senderAddress=192.168.1.1,senderPort=4001 type :
JMX.mbean.unregistered
20:06:39,818 DEBUG [MapperListener] Handle
geronimo:type=IDataSender,senderAddress=192.168.1.1,senderPort=4001 type :
JMX.mbean.unregistered
20:06:39,818 DEBUG [MapperListener] Handle
geronimo:type=IDataSender,senderAddress=192.168.1.1,senderPort=4001 type :
JMX.mbean.unregistered
20:06:39,818 DEBUG [DataSender] Sender close socket to [192.168.1.1:4,001]
(close count 1)
20:06:39,818 DEBUG [DataSender] Sender disconnect from [192.168.1.1:4,001]
(disconnect count 1)
----------
(*3)
nodeB
---------------
20:06:40,640 DEBUG [CoyoteAdapter] Requested cookie session id is
7160C8614D20687D3548E8488AB65AC3.nodeA
20:06:40,641 DEBUG [JvmRouteBinderValve] Found Cluster DeltaManager [EMAIL
PROTECTED] at /ClusterCheck
20:06:40,641 DEBUG [JvmRouteBinderValve] Detected a failover with different
jvmRoute - orginal route: [nodeA] new one: [nodeB] at session id
[7160C8614D20687D3548E8488AB65AC3.nodeA]
20:06:40,641 DEBUG [JvmRouteBinderValve] Found Cluster DeltaManager [EMAIL
PROTECTED] at /ClusterCheck
20:06:40,642 DEBUG [JvmRouteBinderValve] Setting cookie with session id
[7160C8614D20687D3548E8488AB65AC3.nodeB] name: [JSESSIONID] path:
[/ClusterCheck] secure: [false]
20:06:40,643 DEBUG [JvmRouteBinderValve] Set Orginal Session id at request
attriute org.apache.catalina.cluster.session.JvmRouteOrignalSessionID value:
7160C8614D20687D3548E8488AB65AC3.nodeA
20:06:40,648 DEBUG [DataSender] Create sender [/192.168.1.3:4,001]
20:06:40,650 DEBUG [DataSender] Sender open socket to [192.168.1.3:4,001] (open
count 1)
20:06:40,663 DEBUG [JvmRouteBinderValve] Changed session from
[7160C8614D20687D3548E8488AB65AC3.nodeA] to
[7160C8614D20687D3548E8488AB65AC3.nodeB]
--------------
nodeC
--------------
20:06:40,572 DEBUG [SimpleTcpCluster] Assuming clocks are synched: Replication
for
7160C8614D20687D3548E8488AB65AC3.nodeA#-#localhost#-#/ClusterCheck#-#0#-#1162811200571
took=-72 ms.
20:06:40,580 DEBUG [SimpleTcpCluster] Message [EMAIL PROTECTED] from type
org.apache.catalina.cluster.session.SessionIDMessage transfered but no listener
registered
20:06:40,652 DEBUG [SimpleTcpCluster] Assuming clocks are synched: Replication
for 7160C8614D20687D3548E8488AB65AC3.nodeB-1162811200691 took=-39 ms.
20:06:40,652 DEBUG [DeltaManager] Manager [/ClusterCheck]: Received
SessionMessage of type=(SESSION-DELTA) from
[org.apache.catalina.cluster.mcast.McastMember[tcp://192.168.1.2:4001,catalina,192.168.1.2,4001,
alive=113760]]
--------------
(*4)
nodeB
---------------
20:06:43,677 DEBUG [CoyoteAdapter] Requested cookie session id is
7160C8614D20687D3548E8488AB65AC3.nodeB
20:06:43,677 DEBUG [JvmRouteBinderValve] Found Cluster DeltaManager [EMAIL
PROTECTED] at /ClusterCheck
20:06:43,677 DEBUG [JvmRouteBinderValve] Turnover Check time 0 msec
20:06:43,678 DEBUG [MsgContext] COMMIT
20:06:43,678 DEBUG [JkInputStream] COMMIT sending headers [EMAIL PROTECTED] ===
MimeHeaders ===
20:06:43,678 DEBUG [MsgContext] CLOSE
20:06:43,678 DEBUG [REQ_TIME] Time pre=0/ service=1 242 /ClusterCheck/counter
20:06:43,679 DEBUG [ReplicationValve] Invoking replication request on
/ClusterCheck/counter
20:06:43,679 DEBUG [DeltaManager] Manager [/ClusterCheck]: create session
message [7160C8614D20687D3548E8488AB65AC3.nodeB] delta request.
20:06:43,721 DEBUG [HandlerRequest] Invoke returned 0
---------------
nodeC
---------------
20:06:43,637 DEBUG [SimpleTcpCluster] Assuming clocks are synched: Replication
for 7160C8614D20687D3548E8488AB65AC3.nodeB-1162811203679 took=-42 ms.
20:06:43,637 DEBUG [DeltaManager] Manager [/ClusterCheck]: Received
SessionMessage of type=(SESSION-DELTA) from
[org.apache.catalina.cluster.mcast.McastMember[tcp://192.168.1.2:4001,catalina,192.168.1.2,4001,
alive=116748]]
---------------
(*5)
nodeC
---------------
20:07:03,844 INFO [SimpleTcpCluster] Received member
disappeared:org.apache.catalina.cluster.mcast.McastMember[tcp://192.168.1.2:4001,catalina,192.168.1.2,4001,
alive=133704]
---------------
(*6)
nodeC
---------------
20:07:04,950 DEBUG [CoyoteAdapter] Requested cookie session id is
7160C8614D20687D3548E8488AB65AC3.nodeB
20:07:04,950 DEBUG [StandardWrapper] Allocating non-STM instance
20:07:04,976 DEBUG [DeltaManager] Created a DeltaSession with Id
[E5F29B4F1C7F849618B4442076B84DB1.nodeC] Total count=2
20:07:04,983 DEBUG [MsgContext] COMMIT
20:07:04,985 DEBUG [JkInputStream] COMMIT sending headers [EMAIL PROTECTED] ===
MimeHeaders ===
Set-Cookie = JSESSIONID=E5F29B4F1C7F849618B4442076B84DB1.nodeC;
Path=/ClusterCheck
20:07:04,986 DEBUG [MsgContext] CLOSE
---------------
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
http://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
