[ http://issues.apache.org/jira/browse/GERONIMO-2577?page=all ]
Kaoru Matsumura updated GERONIMO-2577:
--------------------------------------
Attachment: geronimo-new.log
Adding information
I have attached the whole geronimo.log(except [McastService] ping) of the last
remaining node.
in using your geronimo-web-new.xml.
15:20:40 first node was down.
15:22:50 second node was down.
15:23:07 new sessionid was created.
> 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: Tomcat, Clustering
> 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
> Attachments: context.xml, geronimo-new.log, geronimo-web-new.xml,
> geronimo-web-nodeB.xml, geronimo-web-nodeC.xml, geronimo-web.xml,
> server-nodeA.xml, server-nodeB.xml, server-nodeC.xml
>
>
> 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
