[jboss-jira] [JBoss JIRA] (WFLY-3711) Topology updates of EJBClient ClusterContexts not being processed correctly after failover

Richard Achmatowicz (JIRA) issues at jboss.org
Thu Aug 7 14:02:29 EDT 2014


    [ https://issues.jboss.org/browse/WFLY-3711?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12991368#comment-12991368 ] 

Richard Achmatowicz edited comment on WFLY-3711 at 8/7/14 2:00 PM:
-------------------------------------------------------------------

The various registry callbacks then cause messages to be sent from server to client along all open EJBClient <--> EJBRemoteConnector connections:

{noformat}
[nrla at lenovo surefire-reports]$ grep Registry org.jboss.as.test.clustering.cluster.ejb.remote.RemoteFailoverTestCase-SYNC-tcp-output.txt 
// node-0, node-1 start up and deploy clustered app
16:00:55,432 INFO  [stdout] (MSC service thread 1-3) Registry collector service started on node node-0
16:01:02,046 INFO  [stdout] (MSC service thread 1-2) Registry collector service started on node node-1
16:01:10,575 INFO  [stdout] (MSC service thread 1-8) Registry for cluster ejb added on node node-0
16:01:13,624 INFO  [stdout] (MSC service thread 1-5) Registry for cluster ejb added on node node-1
Registry: Received a cluster node(s) addition message, for cluster named ejb with 2 nodes [ClusterNode{clusterName='ejb', nodeName='node-0', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8080}], resolvedDestination=[Destination address=127.0.0.1, destination port=8080]}, ClusterNode{clusterName='ejb', nodeName='node-1', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8180}], resolvedDestination=[Destination address=127.0.0.1, destination port=8180]}]
Registry: Received a cluster node(s) addition message, for cluster named ejb with 2 nodes [ClusterNode{clusterName='ejb', nodeName='node-0', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8080}], resolvedDestination=[Destination address=127.0.0.1, destination port=8080]}, ClusterNode{clusterName='ejb', nodeName='node-1', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8180}], resolvedDestination=[Destination address=127.0.0.1, destination port=8180]}]

// node-0 undeploys clustered app
16:01:15,998 INFO  [stdout] (MSC service thread 1-8) Registry for cluster ejb removed on node node-0
16:01:15,999 INFO  [stdout] (MSC service thread 1-8) Registry removed on node node-0  with (key) entries: [node-0, node-1]
16:01:16,004 INFO  [stdout] (remote-thread-0) Registry entries removed on node node-1  for nodes: [node-0]
Registry: Received a cluster node(s) removal message, for cluster named ejb with 1 removed nodes [node-0]

// node-0 deploys clustered app
16:01:16,881 INFO  [stdout] (remote-thread-0) Registry entries added on node node-1 for nodes: [node-0]
Registry: Received a cluster node(s) addition message, for cluster named ejb with 1 nodes [ClusterNode{clusterName='ejb', nodeName='node-0', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8080}], resolvedDestination=[Destination address=127.0.0.1, destination port=8080]}]
16:01:16,883 INFO  [stdout] (MSC service thread 1-6) Registry for cluster ejb added on node node-0
16:01:16,884 INFO  [stdout] (MSC service thread 1-6) Registry added on node node-0 with (key) entries: [node-0, node-1]
Registry: Received a cluster node(s) addition message, for cluster named ejb with 2 nodes [ClusterNode{clusterName='ejb', nodeName='node-0', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8080}], resolvedDestination=[Destination address=127.0.0.1, destination port=8080]}, ClusterNode{clusterName='ejb', nodeName='node-1', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8180}], resolvedDestination=[Destination address=127.0.0.1, destination port=8180]}]

// node-1 undeploys clustered app and shuts down
16:01:22,323 INFO  [stdout] (MSC service thread 1-3) Registry for cluster ejb removed on node node-1
16:01:22,324 INFO  [stdout] (MSC service thread 1-3) Registry removed on node node-1  with (key) entries: [node-0, node-1]
16:01:22,325 INFO  [stdout] (MSC service thread 1-3) Registry collector service stopped on node node-1
16:01:22,328 INFO  [stdout] (remote-thread-0) Registry entries removed on node node-0  for nodes: [node-1]
Registry: Received a cluster node(s) removal message, for cluster named ejb with 1 removed nodes [node-1]

// node-1 starts up and deploys clustered app
16:01:29,490 INFO  [stdout] (MSC service thread 1-1) Registry collector service started on node node-1
16:01:31,047 INFO  [stdout] (remote-thread-0) Registry entries added on node node-0 for nodes: [node-1]
Registry: Received a cluster node(s) addition message, for cluster named ejb with 1 nodes [ClusterNode{clusterName='ejb', nodeName='node-1', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8180}], resolvedDestination=[Destination address=127.0.0.1, destination port=8180]}]
16:01:31,051 INFO  [stdout] (MSC service thread 1-1) Registry for cluster ejb added on node node-1
Registry: Received a cluster node(s) addition message, for cluster named ejb with 2 nodes [ClusterNode{clusterName='ejb', nodeName='node-0', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8080}], resolvedDestination=[Destination address=127.0.0.1, destination port=8080]}, ClusterNode{clusterName='ejb', nodeName='node-1', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8180}], resolvedDestination=[Destination address=127.0.0.1, destination port=8180]}]

// node-0 and node-1 shut down
16:01:39,289 INFO  [stdout] (MSC service thread 1-3) Registry for cluster ejb removed on node node-0
16:01:39,290 INFO  [stdout] (MSC service thread 1-3) Registry removed on node node-0  with (key) entries: [node-0, node-1]
16:01:39,296 INFO  [stdout] (remote-thread-0) Registry entries removed on node node-1  for nodes: [node-0]
Registry: Received a cluster node(s) removal message, for cluster named ejb with 1 removed nodes [node-0]
16:01:39,756 INFO  [stdout] (MSC service thread 1-4) Registry for cluster ejb removed on node node-1
16:01:39,757 INFO  [stdout] (MSC service thread 1-4) Registry removed on node node-1  with (key) entries: [node-1]

// no cluster node removal message for node-1!
// no "cluster context closed" messages appearing on client when both servers stop
{noformat}
 


was (Author: rachmato):
The various registry callbacks then cause messages to be send from server to client along all open EJBClient <--> EJBRemoteConnector connections:

{noformat}
[nrla at lenovo surefire-reports]$ grep Registry org.jboss.as.test.clustering.cluster.ejb.remote.RemoteFailoverTestCase-SYNC-tcp-output.txt 
// node-0, node-1 start up and deploy clustered app
16:00:55,432 INFO  [stdout] (MSC service thread 1-3) Registry collector service started on node node-0
16:01:02,046 INFO  [stdout] (MSC service thread 1-2) Registry collector service started on node node-1
16:01:10,575 INFO  [stdout] (MSC service thread 1-8) Registry for cluster ejb added on node node-0
16:01:13,624 INFO  [stdout] (MSC service thread 1-5) Registry for cluster ejb added on node node-1
Registry: Received a cluster node(s) addition message, for cluster named ejb with 2 nodes [ClusterNode{clusterName='ejb', nodeName='node-0', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8080}], resolvedDestination=[Destination address=127.0.0.1, destination port=8080]}, ClusterNode{clusterName='ejb', nodeName='node-1', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8180}], resolvedDestination=[Destination address=127.0.0.1, destination port=8180]}]
Registry: Received a cluster node(s) addition message, for cluster named ejb with 2 nodes [ClusterNode{clusterName='ejb', nodeName='node-0', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8080}], resolvedDestination=[Destination address=127.0.0.1, destination port=8080]}, ClusterNode{clusterName='ejb', nodeName='node-1', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8180}], resolvedDestination=[Destination address=127.0.0.1, destination port=8180]}]

// node-0 undeploys clustered app
16:01:15,998 INFO  [stdout] (MSC service thread 1-8) Registry for cluster ejb removed on node node-0
16:01:15,999 INFO  [stdout] (MSC service thread 1-8) Registry removed on node node-0  with (key) entries: [node-0, node-1]
16:01:16,004 INFO  [stdout] (remote-thread-0) Registry entries removed on node node-1  for nodes: [node-0]
Registry: Received a cluster node(s) removal message, for cluster named ejb with 1 removed nodes [node-0]

// node-0 deploys clustered app
16:01:16,881 INFO  [stdout] (remote-thread-0) Registry entries added on node node-1 for nodes: [node-0]
Registry: Received a cluster node(s) addition message, for cluster named ejb with 1 nodes [ClusterNode{clusterName='ejb', nodeName='node-0', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8080}], resolvedDestination=[Destination address=127.0.0.1, destination port=8080]}]
16:01:16,883 INFO  [stdout] (MSC service thread 1-6) Registry for cluster ejb added on node node-0
16:01:16,884 INFO  [stdout] (MSC service thread 1-6) Registry added on node node-0 with (key) entries: [node-0, node-1]
Registry: Received a cluster node(s) addition message, for cluster named ejb with 2 nodes [ClusterNode{clusterName='ejb', nodeName='node-0', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8080}], resolvedDestination=[Destination address=127.0.0.1, destination port=8080]}, ClusterNode{clusterName='ejb', nodeName='node-1', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8180}], resolvedDestination=[Destination address=127.0.0.1, destination port=8180]}]

// node-1 undeploys clustered app and shuts down
16:01:22,323 INFO  [stdout] (MSC service thread 1-3) Registry for cluster ejb removed on node node-1
16:01:22,324 INFO  [stdout] (MSC service thread 1-3) Registry removed on node node-1  with (key) entries: [node-0, node-1]
16:01:22,325 INFO  [stdout] (MSC service thread 1-3) Registry collector service stopped on node node-1
16:01:22,328 INFO  [stdout] (remote-thread-0) Registry entries removed on node node-0  for nodes: [node-1]
Registry: Received a cluster node(s) removal message, for cluster named ejb with 1 removed nodes [node-1]

// node-1 starts up and deploys clustered app
16:01:29,490 INFO  [stdout] (MSC service thread 1-1) Registry collector service started on node node-1
16:01:31,047 INFO  [stdout] (remote-thread-0) Registry entries added on node node-0 for nodes: [node-1]
Registry: Received a cluster node(s) addition message, for cluster named ejb with 1 nodes [ClusterNode{clusterName='ejb', nodeName='node-1', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8180}], resolvedDestination=[Destination address=127.0.0.1, destination port=8180]}]
16:01:31,051 INFO  [stdout] (MSC service thread 1-1) Registry for cluster ejb added on node node-1
Registry: Received a cluster node(s) addition message, for cluster named ejb with 2 nodes [ClusterNode{clusterName='ejb', nodeName='node-0', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8080}], resolvedDestination=[Destination address=127.0.0.1, destination port=8080]}, ClusterNode{clusterName='ejb', nodeName='node-1', clientMappings=[ClientMapping{sourceNetworkAddress=/0:0:0:0:0:0:0:0, sourceNetworkMaskBits=0, destinationAddress='127.0.0.1', destinationPort=8180}], resolvedDestination=[Destination address=127.0.0.1, destination port=8180]}]

// node-0 and node-1 shut down
16:01:39,289 INFO  [stdout] (MSC service thread 1-3) Registry for cluster ejb removed on node node-0
16:01:39,290 INFO  [stdout] (MSC service thread 1-3) Registry removed on node node-0  with (key) entries: [node-0, node-1]
16:01:39,296 INFO  [stdout] (remote-thread-0) Registry entries removed on node node-1  for nodes: [node-0]
Registry: Received a cluster node(s) removal message, for cluster named ejb with 1 removed nodes [node-0]
16:01:39,756 INFO  [stdout] (MSC service thread 1-4) Registry for cluster ejb removed on node node-1
16:01:39,757 INFO  [stdout] (MSC service thread 1-4) Registry removed on node node-1  with (key) entries: [node-1]

// no cluster node removal message for node-1!
// no "cluster context closed" messages appearing on client when both servers stop
{noformat}
 

> Topology updates of EJBClient ClusterContexts not being processed correctly after failover
> ------------------------------------------------------------------------------------------
>
>                 Key: WFLY-3711
>                 URL: https://issues.jboss.org/browse/WFLY-3711
>             Project: WildFly
>          Issue Type: Bug
>      Security Level: Public(Everyone can see) 
>          Components: Clustering
>    Affects Versions: 9.0.0.Beta1
>            Reporter: Richard Achmatowicz
>            Assignee: Richard Achmatowicz
>
> ClusterContexts are used by EJBClient to keep track of the current set of nodes in a cluster, so that if an EJBClient invocation fails on one node, it may failover to another node in the same cluster. The ClusterContext is made up of ClusterNodeManagers which are responsible for setting up the connections between the EJBClient and the nodes in the cluster.
> Cluster topology updates are sent to registered EJBClients whenever the cluster topology changes (nodes join, nodes leave a cluster). Thse topology updates are processed on the client side by ClusterTopologyUpdateHandler and are used to update the current contents of the associated ClusterContext held on the client.
> The current implementation of the handling of topology updates does not correctly handle the addition/removal of ClusterNodeManagers from the cluster context - namely, rather than check whether or not a new ClusterNodeManager really needs to be added, ClusterNodeManagers are added for every node in the received topology update, leading to many unnecessary EJBReceivers and their channels being created.
> The logs show that up to 18 cluster node manager instances may be created, have their EJBReceivers registered and channels to the remote node created, when only one node has been added to the cluster.



--
This message was sent by Atlassian JIRA
(v6.2.6#6264)


More information about the jboss-jira mailing list