Return-Path: Delivered-To: apmail-geronimo-dev-archive@www.apache.org Received: (qmail 96846 invoked from network); 17 Nov 2006 12:28:10 -0000 Received: from hermes.apache.org (HELO mail.apache.org) (140.211.11.2) by minotaur.apache.org with SMTP; 17 Nov 2006 12:28:09 -0000 Received: (qmail 15149 invoked by uid 500); 17 Nov 2006 12:28:13 -0000 Delivered-To: apmail-geronimo-dev-archive@geronimo.apache.org Received: (qmail 14895 invoked by uid 500); 17 Nov 2006 12:28:10 -0000 Mailing-List: contact dev-help@geronimo.apache.org; run by ezmlm Precedence: bulk list-help: list-unsubscribe: List-Post: Reply-To: dev@geronimo.apache.org List-Id: Delivered-To: mailing list dev@geronimo.apache.org Received: (qmail 14845 invoked by uid 99); 17 Nov 2006 12:28:10 -0000 Received: from herse.apache.org (HELO herse.apache.org) (140.211.11.133) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 17 Nov 2006 04:28:10 -0800 X-ASF-Spam-Status: No, hits=0.0 required=10.0 tests= X-Spam-Check-By: apache.org Received: from [140.211.11.4] (HELO brutus.apache.org) (140.211.11.4) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 17 Nov 2006 04:27:59 -0800 Received: from brutus (localhost [127.0.0.1]) by brutus.apache.org (Postfix) with ESMTP id 2C09E714329 for ; Fri, 17 Nov 2006 04:27:39 -0800 (PST) Message-ID: <33483158.1163766459177.JavaMail.jira@brutus> Date: Fri, 17 Nov 2006 04:27:39 -0800 (PST) From: "Kaoru Matsumura (JIRA)" To: dev@geronimo.apache.org Subject: [jira] Created: (GERONIMO-2577) Geronimo cluster (Tomcat Version)cannot continue the HttpSession when current node is down. MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable X-Virus-Checked: Checked by ClamAV on apache.org Geronimo cluster (Tomcat Version)cannot continue the HttpSession when curre= nt node is down.=20 ---------------------------------------------------------------------------= ----------------- 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 =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D 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=E3=80=80Files =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D We refer http://cwiki.apache.org/GMOxDOC11/clustering-sample-application.ht= ml * config.xml We add the following parameters to the standard configuration.=20 name=3DGeronimo jvmRoute=3DnodeA Operations =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D 1 Have browser access to Test Application , and reload several times.(*1) H= ttpSession object is created on the nodeA. 2 And then, We kill the process of geronimo on the nodeA with $kill -9 .(*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 .(*5) 6 Reload the browser at one time.(And then, We expect that the process cont= inues 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 =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D When replication module is SimpleTcpReplicationManager, the geronimo cluste= r can continue the process. Debug levels logs =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D (*1) nodeA ---------- 20:06:17,736 DEBUG [CoyoteAdapter] Requested cookie session id is 7160C861= 4D20687D3548E8488AB65AC3.nodeA 20:06:17,736 DEBUG [JvmRouteBinderValve] Found Cluster DeltaManager org.apa= che.catalina.cluster.session.DeltaManager@2cb491 at /ClusterCheck 20:06:17,736 DEBUG [JvmRouteBinderValve] Turnover Check time 0 msec 20:06:17,737 DEBUG [MsgContext] COMMIT=20 20:06:17,737 DEBUG [JkInputStream] COMMIT sending headers org.apache.coyote= .Response@118994d =3D=3D=3D MimeHeaders =3D=3D=3D 20:06:17,737 DEBUG [MsgContext] CLOSE=20 20:06:17,738 DEBUG [REQ_TIME] Time pre=3D0/ service=3D2 242 /ClusterCheck/c= ounter 20:06:17,738 DEBUG [ReplicationValve] Invoking replication request on /Clus= terCheck/counter 20:06:17,738 DEBUG [DeltaManager] Manager [/ClusterCheck]: create session m= essage [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=3D58960] ----------- nodeC ----------- 20:06:17,655 DEBUG [SimpleTcpCluster] Assuming clocks are synched: Replicat= ion for 7160C8614D20687D3548E8488AB65AC3.nodeA-1162811177738 took=3D-83 ms. 20:06:17,655 DEBUG [DeltaManager] Manager [/ClusterCheck]: Received Session= Message of type=3D(SESSION-DELTA) from [org.apache.catalina.cluster.mcast.M= castMember[tcp://192.168.1.1:4001,catalina,192.168.1.1,4001, alive=3D130441= ]] 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.apach= e.catalina.cluster.mcast.McastMember[tcp://192.168.1.1:4001,catalina,192.16= 8.1.1,4001, alive=3D149288] 20:06:39,818 DEBUG [MapperListener] Handle geronimo:type=3DIDataSender,send= erAddress=3D192.168.1.1,senderPort=3D4001 type : JMX.mbean.unregistered 20:06:39,818 DEBUG [MapperListener] Handle geronimo:type=3DIDataSender,send= erAddress=3D192.168.1.1,senderPort=3D4001 type : JMX.mbean.unregistered 20:06:39,818 DEBUG [MapperListener] Handle geronimo:type=3DIDataSender,send= erAddress=3D192.168.1.1,senderPort=3D4001 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 --------------- 20:06:40,640 DEBUG [CoyoteAdapter] Requested cookie session id is 7160C861= 4D20687D3548E8488AB65AC3.nodeA 20:06:40,641 DEBUG [JvmRouteBinderValve] Found Cluster DeltaManager org.apa= che.catalina.cluster.session.DeltaManager@16d383a at /ClusterCheck 20:06:40,641 DEBUG [JvmRouteBinderValve] Detected a failover with different= jvmRoute - orginal route: [nodeA] new one: [nodeB] at session id [7160C861= 4D20687D3548E8488AB65AC3.nodeA] 20:06:40,641 DEBUG [JvmRouteBinderValve] Found Cluster DeltaManager org.apa= che.catalina.cluster.session.DeltaManager@16d383a at /ClusterCheck 20:06:40,642 DEBUG [JvmRouteBinderValve] Setting cookie with session id [71= 60C8614D20687D3548E8488AB65AC3.nodeB] name: [JSESSIONID] path: [/ClusterChe= ck] 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 [7160C8614D20= 687D3548E8488AB65AC3.nodeA] to [7160C8614D20687D3548E8488AB65AC3.nodeB] -------------- nodeC -------------- 20:06:40,572 DEBUG [SimpleTcpCluster] Assuming clocks are synched: Replicat= ion for 7160C8614D20687D3548E8488AB65AC3.nodeA#-#localhost#-#/ClusterCheck#= -#0#-#1162811200571 took=3D-72 ms. 20:06:40,580 DEBUG [SimpleTcpCluster] Message org.apache.catalina.cluster.s= ession.SessionIDMessage@128ccdf from type org.apache.catalina.cluster.sessi= on.SessionIDMessage transfered but no listener registered 20:06:40,652 DEBUG [SimpleTcpCluster] Assuming clocks are synched: Replicat= ion for 7160C8614D20687D3548E8488AB65AC3.nodeB-1162811200691 took=3D-39 ms. 20:06:40,652 DEBUG [DeltaManager] Manager [/ClusterCheck]: Received Session= Message of type=3D(SESSION-DELTA) from [org.apache.catalina.cluster.mcast.M= castMember[tcp://192.168.1.2:4001,catalina,192.168.1.2,4001, alive=3D113760= ]] -------------- (*4) nodeB --------------- 20:06:43,677 DEBUG [CoyoteAdapter] Requested cookie session id is 7160C861= 4D20687D3548E8488AB65AC3.nodeB 20:06:43,677 DEBUG [JvmRouteBinderValve] Found Cluster DeltaManager org.apa= che.catalina.cluster.session.DeltaManager@16d383a at /ClusterCheck 20:06:43,677 DEBUG [JvmRouteBinderValve] Turnover Check time 0 msec 20:06:43,678 DEBUG [MsgContext] COMMIT=20 20:06:43,678 DEBUG [JkInputStream] COMMIT sending headers org.apache.coyote= .Response@11e2b21 =3D=3D=3D MimeHeaders =3D=3D=3D 20:06:43,678 DEBUG [MsgContext] CLOSE=20 20:06:43,678 DEBUG [REQ_TIME] Time pre=3D0/ service=3D1 242 /ClusterCheck/c= ounter 20:06:43,679 DEBUG [ReplicationValve] Invoking replication request on /Clus= terCheck/counter 20:06:43,679 DEBUG [DeltaManager] Manager [/ClusterCheck]: create session m= essage [7160C8614D20687D3548E8488AB65AC3.nodeB] delta request. 20:06:43,721 DEBUG [HandlerRequest] Invoke returned 0 --------------- nodeC --------------- 20:06:43,637 DEBUG [SimpleTcpCluster] Assuming clocks are synched: Replicat= ion for 7160C8614D20687D3548E8488AB65AC3.nodeB-1162811203679 took=3D-42 ms. 20:06:43,637 DEBUG [DeltaManager] Manager [/ClusterCheck]: Received Session= Message of type=3D(SESSION-DELTA) from [org.apache.catalina.cluster.mcast.M= castMember[tcp://192.168.1.2:4001,catalina,192.168.1.2,4001, alive=3D116748= ]] --------------- (*5) nodeC --------------- 20:07:03,844 INFO [SimpleTcpCluster] Received member disappeared:org.apach= e.catalina.cluster.mcast.McastMember[tcp://192.168.1.2:4001,catalina,192.16= 8.1.2,4001, alive=3D133704] --------------- (*6) nodeC --------------- 20:07:04,950 DEBUG [CoyoteAdapter] Requested cookie session id is 7160C861= 4D20687D3548E8488AB65AC3.nodeB 20:07:04,950 DEBUG [StandardWrapper] Allocating non-STM instance 20:07:04,976 DEBUG [DeltaManager] Created a DeltaSession with Id [E5F29B4F1= C7F849618B4442076B84DB1.nodeC] Total count=3D2 20:07:04,983 DEBUG [MsgContext] COMMIT=20 20:07:04,985 DEBUG [JkInputStream] COMMIT sending headers org.apache.coyote= .Response@1222045 =3D=3D=3D MimeHeaders =3D=3D=3D Set-Cookie =3D JSESSIONID=3DE5F29B4F1C7F849618B4442076B84DB1.nodeC; Path=3D= /ClusterCheck 20:07:04,986 DEBUG [MsgContext] CLOSE=20 --------------- --=20 This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: htt= p://issues.apache.org/jira/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira