[ https://issues.apache.org/jira/browse/SLING-4302?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Stefan Egli resolved SLING-4302. -------------------------------- Resolution: Fixed test made more robust > ClusterTest.testStableClusterId sometimes fails > ----------------------------------------------- > > Key: SLING-4302 > URL: https://issues.apache.org/jira/browse/SLING-4302 > Project: Sling > Issue Type: Test > Components: Extensions > Affects Versions: Discovery Impl 1.0.12 > Reporter: Stefan Egli > Assignee: Stefan Egli > Fix For: Discovery Impl 1.0.14 > > > Recently, ClusterTest.testStableClusterId sometimes fails, eg > https://builds.apache.org/job/sling-trunk-1.8/org.apache.sling$org.apache.sling.discovery.impl/607/testReport/org.apache.sling.discovery.impl.cluster/ClusterTest/testStableClusterId/ > {code} > Error Message > expected:<2> but was:<1> > Stacktrace > java.lang.AssertionError: expected:<2> but was:<1> > at org.junit.Assert.fail(Assert.java:88) > at org.junit.Assert.failNotEquals(Assert.java:743) > at org.junit.Assert.assertEquals(Assert.java:118) > at org.junit.Assert.assertEquals(Assert.java:555) > at org.junit.Assert.assertEquals(Assert.java:542) > at > org.apache.sling.discovery.impl.cluster.ClusterTest.testStableClusterId(ClusterTest.java:184) > Standard Output > 13.01.2015 12:03:06 *INFO * [main] Instance: <init>: starting > slingId=e997787e-e6f2-4d54-af7d-19dcfb9fbc9a, debugName=firstInstance > 13.01.2015 12:03:06 *INFO * [ObservationManager] VotingHelper: > getWinningVoting: no ongoing votings parent resource found > 13.01.2015 12:03:06 *INFO * [ObservationManager] VotingHelper: > listOpenNonWinningVotings: no ongoing votings parent resource found > 13.01.2015 12:03:08 *INFO * [main] Instance: <init>: starting > slingId=808c627d-fc2f-472c-8b39-bdcdc8ead24f, debugName=secondInstance > 13.01.2015 12:03:18 *INFO * [main] ClusterTest: testStableClusterId: start > 13.01.2015 12:03:18 *INFO * [main] Instance: stop: stopping > slingId=808c627d-fc2f-472c-8b39-bdcdc8ead24f, debugName=secondInstance > 13.01.2015 12:03:18 *INFO * [main] Instance: stop: removing listener for > slingId=808c627d-fc2f-472c-8b39-bdcdc8ead24f: > org.apache.sling.discovery.impl.setup.Instance$1@13e880b5 > 13.01.2015 12:03:18 *INFO * [main] Instance: stop: stopped > slingId=808c627d-fc2f-472c-8b39-bdcdc8ead24f, debugName=secondInstance > 13.01.2015 12:03:18 *INFO * [main] Instance: stop: stopping > slingId=e997787e-e6f2-4d54-af7d-19dcfb9fbc9a, debugName=firstInstance > 13.01.2015 12:03:18 *INFO * [main] Instance: stop: removing listener for > slingId=e997787e-e6f2-4d54-af7d-19dcfb9fbc9a: > org.apache.sling.discovery.impl.setup.Instance$1@73c7a727 > 13.01.2015 12:03:18 *INFO * [main] Instance: stop: stopped > slingId=e997787e-e6f2-4d54-af7d-19dcfb9fbc9a, debugName=firstInstance > 13.01.2015 12:03:18 *INFO * [main] Instance: <init>: starting > slingId=64d74699-661e-42aa-be7f-076c93773326, debugName=firstInstance > 13.01.2015 12:03:18 *INFO * [main] Instance: <init>: starting > slingId=de74b83b-c913-40b0-a958-eba71d12a867, debugName=secondInstance > 13.01.2015 12:03:20 *INFO * [main] Instance: Instance > [64d74699-661e-42aa-be7f-076c93773326] issues a heartbeat now Tue Jan 13 > 12:03:20 UTC 2015 > 13.01.2015 12:03:20 *INFO * [main] HeartbeatHandler: doCheckView: > votingHandler is null! > 13.01.2015 12:03:20 *INFO * [main] VotingHelper: getWinningVoting: no ongoing > votings parent resource found > 13.01.2015 12:03:20 *INFO * [main] VotingHelper: listOpenNonWinningVotings: > no ongoing votings parent resource found > 13.01.2015 12:03:20 *INFO * [main] Instance: Instance > [de74b83b-c913-40b0-a958-eba71d12a867] issues a heartbeat now Tue Jan 13 > 12:03:20 UTC 2015 > 13.01.2015 12:03:57 *INFO * [main] HeartbeatHandler: doCheckView: > votingHandler is null! > 13.01.2015 12:03:57 *INFO * [pool-1-thread-2] HeartbeatHandler: doCheckView: > votingHandler is null! > 13.01.2015 12:03:57 *INFO * [main] Instance: Instance > [64d74699-661e-42aa-be7f-076c93773326] issues a heartbeat now Tue Jan 13 > 12:03:57 UTC 2015 > 13.01.2015 12:03:57 *INFO * [main] ClusterViewServiceImpl: > getEstablishedView: the existing established view does not incude the local > instance yet! Assuming isolated mode. If this occurs at runtime - other than > at startup - it could cause a pseudo-network-partition, see SLING-3432. > Consider increasing heartbeatTimeout then! > 13.01.2015 12:03:58 *INFO * [main] HeartbeatHandler: doCheckView: > votingHandler is null! > 13.01.2015 12:03:58 *INFO * [main] Instance: Instance > [de74b83b-c913-40b0-a958-eba71d12a867] issues a heartbeat now Tue Jan 13 > 12:03:58 UTC 2015 > 13.01.2015 12:03:59 *INFO * [main] HeartbeatHandler: doCheckView: > votingHandler is null! > 13.01.2015 12:03:59 *INFO * [main] Instance: Instance > [64d74699-661e-42aa-be7f-076c93773326] issues a heartbeat now Tue Jan 13 > 12:03:59 UTC 2015 > 13.01.2015 12:03:59 *INFO * [pool-1-thread-3] HeartbeatHandler: doCheckView: > votingHandler is null! > 13.01.2015 12:03:59 *INFO * [main] ClusterViewServiceImpl: > getEstablishedView: the existing established view does not incude the local > instance yet! Assuming isolated mode. If this occurs at runtime - other than > at startup - it could cause a pseudo-network-partition, see SLING-3432. > Consider increasing heartbeatTimeout then! > 13.01.2015 12:04:00 *INFO * [main] HeartbeatHandler: doCheckView: > votingHandler is null! > 13.01.2015 12:04:00 *INFO * [main] Instance: Instance > [de74b83b-c913-40b0-a958-eba71d12a867] issues a heartbeat now Tue Jan 13 > 12:04:00 UTC 2015 > 13.01.2015 12:04:01 *INFO * [main] ClusterViewServiceImpl: > getEstablishedView: the existing established view does not incude the local > instance yet! Assuming isolated mode. If this occurs at runtime - other than > at startup - it could cause a pseudo-network-partition, see SLING-3432. > Consider increasing heartbeatTimeout then! > 13.01.2015 12:04:01 *INFO * [main] HeartbeatHandler: doCheckView: > votingHandler is null! > 13.01.2015 12:04:02 *INFO * [main] ClusterViewServiceImpl: > getEstablishedView: the existing established view does not incude the local > instance yet! Assuming isolated mode. If this occurs at runtime - other than > at startup - it could cause a pseudo-network-partition, see SLING-3432. > Consider increasing heartbeatTimeout then! > 13.01.2015 12:04:02 *INFO * [main] Instance: dumpRepo: ====== START ===== > 13.01.2015 12:04:02 *INFO * [main] Instance: dumpRepo: repo = > org.apache.jackrabbit.core.RepositoryImpl@3f685162 > 13.01.2015 12:04:02 *INFO * [main] Instance: / -- jcr:mixinTypes=<unknown > type=7/> jcr:primaryType=<unknown type=7/> > 13.01.2015 12:04:02 *INFO * [main] Instance: /var -- > jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder > 13.01.2015 12:04:02 *INFO * [main] Instance: /discovery -- > jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder > 13.01.2015 12:04:02 *INFO * [main] Instance: /impl -- > jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder > 13.01.2015 12:04:02 *INFO * [main] Instance: /clusterInstances -- > jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder > 13.01.2015 12:04:02 *INFO * [main] Instance: > /64d74699-661e-42aa-be7f-076c93773326 -- > runtimeId=db6da1a2-efed-45f7-991d-149288c2f416 lastHeartbeat=Tue Jan 13 > 12:04:00 UTC 2015 sling:resourceType=sling:Folder jcr:primaryType=<unknown > type=7/> > leaderElectionId=0_0000001421150598702_64d74699-661e-42aa-be7f-076c93773326 > 13.01.2015 12:04:02 *INFO * [main] Instance: /properties -- > jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder > 13.01.2015 12:04:02 *INFO * [main] Instance: > /de74b83b-c913-40b0-a958-eba71d12a867 -- > runtimeId=51d73731-6329-4b2d-bc0e-c557b3627f2f lastHeartbeat=Tue Jan 13 > 12:04:01 UTC 2015 sling:resourceType=sling:Folder jcr:primaryType=<unknown > type=7/> > leaderElectionId=0_0000001421150599274_de74b83b-c913-40b0-a958-eba71d12a867 > 13.01.2015 12:04:02 *INFO * [main] Instance: /properties -- > jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder > 13.01.2015 12:04:02 *INFO * [main] Instance: /ongoingVotings -- > jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder > 13.01.2015 12:04:02 *INFO * [main] Instance: /previousView -- > jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder > 13.01.2015 12:04:02 *INFO * [main] Instance: > /5557e13b-8f71-4620-bb60-e5cd3fab9f6a -- > clusterId=3c07f561-4d07-4e0b-a69e-2c21621887ae promotedAt=Tue Jan 13 12:04:00 > UTC 2015 promotedBy=64d74699-661e-42aa-be7f-076c93773326 > leaderId=64d74699-661e-42aa-be7f-076c93773326 > clusterIdDefinedBy=de74b83b-c913-40b0-a958-eba71d12a867 > sling:resourceType=sling:Folder votingStart=Tue Jan 13 12:04:00 UTC 2015 > clusterIdDefinedAt=Tue Jan 13 12:03:57 UTC 2015 jcr:primaryType=<unknown > type=7/> > leaderElectionId=0_0000001421150598702_64d74699-661e-42aa-be7f-076c93773326 > 13.01.2015 12:04:02 *INFO * [main] Instance: /members -- > jcr:primaryType=<unknown type=7/> > 13.01.2015 12:04:02 *INFO * [main] Instance: > /64d74699-661e-42aa-be7f-076c93773326 -- initiator=true > jcr:primaryType=<unknown type=7/> > leaderElectionId=0_0000001421150598702_64d74699-661e-42aa-be7f-076c93773326 > 13.01.2015 12:04:02 *INFO * [main] Instance: /establishedView -- > jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder > 13.01.2015 12:04:02 *INFO * [main] Instance: > /53ffc741-67c0-40b4-a5b5-df2b9fb70e34 -- > clusterId=3c07f561-4d07-4e0b-a69e-2c21621887ae promotedAt=Tue Jan 13 12:04:02 > UTC 2015 promotedBy=de74b83b-c913-40b0-a958-eba71d12a867 > leaderId=de74b83b-c913-40b0-a958-eba71d12a867 > clusterIdDefinedBy=de74b83b-c913-40b0-a958-eba71d12a867 > sling:resourceType=sling:Folder votingStart=Tue Jan 13 12:04:01 UTC 2015 > clusterIdDefinedAt=Tue Jan 13 12:03:57 UTC 2015 jcr:primaryType=<unknown > type=7/> > leaderElectionId=0_0000001421150599274_de74b83b-c913-40b0-a958-eba71d12a867 > 13.01.2015 12:04:02 *INFO * [main] Instance: /members -- > jcr:primaryType=<unknown type=7/> > 13.01.2015 12:04:02 *INFO * [main] Instance: > /de74b83b-c913-40b0-a958-eba71d12a867 -- initiator=true > jcr:primaryType=<unknown type=7/> > leaderElectionId=0_0000001421150599274_de74b83b-c913-40b0-a958-eba71d12a867 > 13.01.2015 12:04:02 *INFO * [main] Instance: dumpRepo: ====== END ===== > 13.01.2015 12:04:02 *INFO * [main] ClusterViewServiceImpl: > getEstablishedView: the existing established view does not incude the local > instance yet! Assuming isolated mode. If this occurs at runtime - other than > at startup - it could cause a pseudo-network-partition, see SLING-3432. > Consider increasing heartbeatTimeout then! > 13.01.2015 12:04:02 *INFO * [main] Instance: stop: stopping > slingId=de74b83b-c913-40b0-a958-eba71d12a867, debugName=secondInstance > 13.01.2015 12:04:02 *INFO * [main] Instance: stop: removing listener for > slingId=de74b83b-c913-40b0-a958-eba71d12a867: > org.apache.sling.discovery.impl.setup.Instance$1@a10723a > 13.01.2015 12:04:02 *INFO * [main] Instance: stop: stopped > slingId=de74b83b-c913-40b0-a958-eba71d12a867, debugName=secondInstance > 13.01.2015 12:04:02 *INFO * [main] Instance: stop: stopping > slingId=64d74699-661e-42aa-be7f-076c93773326, debugName=firstInstance > 13.01.2015 12:04:02 *INFO * [main] Instance: stop: removing listener for > slingId=64d74699-661e-42aa-be7f-076c93773326: > org.apache.sling.discovery.impl.setup.Instance$1@57268fc3 > 13.01.2015 12:04:02 *INFO * [main] Instance: stop: stopped > slingId=64d74699-661e-42aa-be7f-076c93773326, debugName=firstInstance > {code} -- This message was sent by Atlassian JIRA (v6.3.4#6332)