geronimo-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Kaoru Matsumura (JIRA)" <j...@apache.org>
Subject [jira] Commented: (GERONIMO-2577) Geronimo cluster (Tomcat Version)cannot continue the HttpSession when current node is down.
Date Mon, 25 Dec 2006 06:52:25 GMT
    [ http://issues.apache.org/jira/browse/GERONIMO-2577?page=comments#action_12460741 ] 
            
Kaoru Matsumura commented on GERONIMO-2577:
-------------------------------------------

Jeff,

I found the following log messages regarding to NextListener in the start of geronimo cluster.
The message "no targets are running for reference NextListener matching ...."  is right ?

nodeA 
---------
2006-12-25-11-10-29-691 DEBUG [GBeanSingleReference] Waiting to start geronimo/ClusterCheck/1.1/war?J2EEApplication=null,WebModule=geronimo/ClusterCheck/1.1/war,j2eeType=MessageListener,name=ClusterSessionListener
because no targets are running for reference NextListener matching the patterns geronimo/ClusterCheck/1.1/war?J2EEApplication=null,WebModule=geronimo/ClusterCheck/1.1/war,j2eeType=MessageListener,name=JvmRouteSessionIDBinderListener
---------

The same messages as nodeB or nodeC.

"ClusterCheck" is our test Application.

> 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-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 org.apache.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:06:17,737 DEBUG [JkInputStream] COMMIT sending headers org.apache.coyote.Response@118994d
=== 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 org.apache.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 [7160C8614D20687D3548E8488AB65AC3.nodeA]
> 20:06:40,641 DEBUG [JvmRouteBinderValve] Found Cluster DeltaManager org.apache.catalina.cluster.session.DeltaManager@16d383a
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 org.apache.catalina.cluster.session.SessionIDMessage@128ccdf
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 org.apache.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:06:43,678 DEBUG [JkInputStream] COMMIT sending headers org.apache.coyote.Response@11e2b21
=== 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 org.apache.coyote.Response@1222045
=== 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

        

Mime
View raw message