[jboss-jira] [JBoss JIRA] (WFLY-5822) Clustering performance regression in ejbremote-dist-sync scenario

Richard Achmatowicz (JIRA) issues at jboss.org
Mon Dec 21 16:32:00 EST 2015


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

Richard Achmatowicz edited comment on WFLY-5822 at 12/21/15 4:31 PM:
---------------------------------------------------------------------

Something a little strange in the logs for the test case. I see this a short time after the test starts:

{noformat}
[JBossINF] 04:46:01,868 INFO  [org.jboss.test.clusterbench.common.ejb.CommonStatefulSBImpl] (EJB default - 9) New SFSB created: org.jboss.test.clusterbench.ejb.stateful.RemoteStatefulSBImpl at 3752b060.
[JBossINF] 04:46:01,869 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Not doing a remote get for key 2d29e0dc-3bfb-42d7-a15e-ac43c88fb4d1 since entry is mapped to current node (perf18) or is in L1. Owners are [perf18, perf21]
[JBossINF] 04:46:01,869 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Not doing a remote get for key UnknownSessionID [5251526551574950557052565268546565555556705070525068555254505668] since entry is mapped to current node (perf18) or is in L1. Owners are [perf18, perf19]
[JBossINF] 04:46:01,870 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Should invoke remotely? true. hasModifications=true, hasRemoteLocksAcquired=false
[JBossINF] 04:46:01,896 INFO  [org.jboss.test.clusterbench.common.ejb.CommonStatefulSBImpl] (EJB default - 9) New SFSB created: org.jboss.test.clusterbench.ejb.stateful.RemoteStatefulSBImpl at 228529d3.
[JBossINF] 04:46:01,896 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Not doing a remote get for key 5cbaadf8-6e55-4f1b-8844-96afef383d33 since entry is mapped to current node (perf18) or is in L1. Owners are [perf18, perf19]
[JBossINF] 04:46:01,897 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Not doing a remote get for key UnknownSessionID [6953704857685049685168535268536966485249675553506769485157667052] since entry is mapped to current node (perf18) or is in L1. Owners are [perf18, perf21]
[JBossINF] 04:46:01,898 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Should invoke remotely? true. hasModifications=true, hasRemoteLocksAcquired=false
[JBossINF] 04:46:01,950 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Should invoke remotely? true. hasModifications=true, hasRemoteLocksAcquired=false
[JBossINF] 04:46:01,983 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Perform remote get for key perf18. topologyId=-1, currentTopologyId=6
[JBossINF] 04:46:02,006 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Remote get of key 'perf18' (topologyId=6) returns ImmortalCacheEntry{key=perf18, value=perf18=[org.jboss.as.network.ClientMapping at 1abcfc74]}
[JBossINF] 04:46:02,007 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Should invoke remotely? false. hasModifications=false, hasRemoteLocksAcquired=false
[JBossINF] 04:46:02,019 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Should invoke remotely? true. hasModifications=true, hasRemoteLocksAcquired=false
[JBossINF] 04:46:02,035 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Perform remote get for key perf18. topologyId=-1, currentTopologyId=6
[JBossINF] 04:46:02,047 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Remote get of key 'perf18' (topologyId=6) returns ImmortalCacheEntry{key=perf18, value=perf18=[org.jboss.as.network.ClientMapping at 5fb9e46a]}
[JBossINF] 04:46:02,048 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Should invoke remotely? false. hasModifications=false, hasRemoteLocksAcquired=false
[JBossINF] 04:46:02,068 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Should invoke remotely? true. hasModifications=true, hasRemoteLocksAcquired=false
[JBossINF] 04:46:02,077 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Perform remote get for key perf18. topologyId=-1, currentTopologyId=6
[JBossINF] 04:46:02,084 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Remote get of key 'perf18' (topologyId=6) returns ImmortalCacheEntry{key=perf18, value=perf18=[org.jboss.as.network.ClientMapping at 5a69864d]}
{noformat}

Namely, that after  period of time, instead of looking up session ids, we are looking up client entry mappings for a single node (perf18, in this case). These lookups go on forever. Investigating.
 


was (Author: rachmato):
Something a little strange in the logs for the test case. I see this a short time after the test starts:

{noformat}
[JBossINF] 04:46:01,868 INFO  [org.jboss.test.clusterbench.common.ejb.CommonStatefulSBImpl] (EJB default - 9) New SFSB created: org.jboss.test.clusterbench.ejb.stateful.RemoteStatefulSBImpl at 3752b060.
[JBossINF] 04:46:01,869 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Not doing a remote get for key 2d29e0dc-3bfb-42d7-a15e-ac43c88fb4d1 since entry is mapped to current node (perf18) or is in L1. Owners are [perf18, perf21]
[JBossINF] 04:46:01,869 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Not doing a remote get for key UnknownSessionID [5251526551574950557052565268546565555556705070525068555254505668] since entry is mapped to current node (perf18) or is in L1. Owners are [perf18, perf19]
[JBossINF] 04:46:01,870 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Should invoke remotely? true. hasModifications=true, hasRemoteLocksAcquired=false
[JBossINF] 04:46:01,896 INFO  [org.jboss.test.clusterbench.common.ejb.CommonStatefulSBImpl] (EJB default - 9) New SFSB created: org.jboss.test.clusterbench.ejb.stateful.RemoteStatefulSBImpl at 228529d3.
[JBossINF] 04:46:01,896 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Not doing a remote get for key 5cbaadf8-6e55-4f1b-8844-96afef383d33 since entry is mapped to current node (perf18) or is in L1. Owners are [perf18, perf19]
[JBossINF] 04:46:01,897 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Not doing a remote get for key UnknownSessionID [6953704857685049685168535268536966485249675553506769485157667052] since entry is mapped to current node (perf18) or is in L1. Owners are [perf18, perf21]
[JBossINF] 04:46:01,898 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Should invoke remotely? true. hasModifications=true, hasRemoteLocksAcquired=false
[JBossINF] 04:46:01,950 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Should invoke remotely? true. hasModifications=true, hasRemoteLocksAcquired=false
[JBossINF] 04:46:01,983 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Perform remote get for key perf18. topologyId=-1, currentTopologyId=6
[JBossINF] 04:46:02,006 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Remote get of key 'perf18' (topologyId=6) returns ImmortalCacheEntry{key=perf18, value=perf18=[org.jboss.as.network.ClientMapping at 1abcfc74]}
[JBossINF] 04:46:02,007 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Should invoke remotely? false. hasModifications=false, hasRemoteLocksAcquired=false
[JBossINF] 04:46:02,019 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Should invoke remotely? true. hasModifications=true, hasRemoteLocksAcquired=false
[JBossINF] 04:46:02,035 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Perform remote get for key perf18. topologyId=-1, currentTopologyId=6
[JBossINF] 04:46:02,047 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Remote get of key 'perf18' (topologyId=6) returns ImmortalCacheEntry{key=perf18, value=perf18=[org.jboss.as.network.ClientMapping at 5fb9e46a]}
[JBossINF] 04:46:02,048 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Should invoke remotely? false. hasModifications=false, hasRemoteLocksAcquired=false
[JBossINF] 04:46:02,068 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Should invoke remotely? true. hasModifications=true, hasRemoteLocksAcquired=false
[JBossINF] 04:46:02,077 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Perform remote get for key perf18. topologyId=-1, currentTopologyId=6
[JBossINF] 04:46:02,084 TRACE [org.infinispan.interceptors.distribution.BaseDistributionInterceptor] (EJB default - 9) Remote get of key 'perf18' (topologyId=6) returns ImmortalCacheEntry{key=perf18, value=perf18=[org.jboss.as.network.ClientMapping at 5a69864d]}
{noformat}

Namely, that after  period of time, instead of looking up session ids, we are looking up client entry mappings for a single node (perf18, in this case). Investigating.
 

> Clustering performance regression in ejbremote-dist-sync scenario 
> ------------------------------------------------------------------
>
>                 Key: WFLY-5822
>                 URL: https://issues.jboss.org/browse/WFLY-5822
>             Project: WildFly
>          Issue Type: Bug
>          Components: Clustering, EJB
>    Affects Versions: 10.0.0.CR5
>            Reporter: Michal Vinkler
>            Assignee: Richard Achmatowicz
>            Priority: Critical
>
> Compared to EAP 6, all SYNC scenarios have the same/better performance except of this one, wonder why?
> Compare these results:
> stress-ejbremote-dist-sync
> 7.0.0.ER2: [throughput|http://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-7x-stress-ejbremote-dist-sync/4/artifact/report/graph-throughput.png]
> 6.4.0.GA: [throughput|http://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-6x-stress-ejbremote-dist-sync_noperf21/1/artifact/report/graph-throughput.png]
> ---------------------------------------
> Just for comparison: ejbremote REPL_SYNC scenario *performs well* on the other hand:
> stress-ejbremote-repl-sync
> 7.0.0.ER2: [throughput|http://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-7x-stress-ejbremote-repl-sync/3/artifact/report/graph-throughput.png]
> 6.4.0.GA: [throughput|http://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-6x-stress-ejbremote-repl-sync_noperf21/2/artifact/report/graph-throughput.png]



--
This message was sent by Atlassian JIRA
(v6.4.11#64026)



More information about the jboss-jira mailing list