Uploaded image for project: 'Sling'
  1. Sling
  2. SLING-4302

ClusterTest.testStableClusterId sometimes fails

    XMLWordPrintableJSON

Details

    • Test
    • Status: Closed
    • Major
    • Resolution: Fixed
    • Discovery Impl 1.0.12
    • Discovery Impl 1.1.0
    • Extensions
    • None

    Description

      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/

      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
      

      Attachments

        Activity

          People

            stefanegli Stefan Egli
            stefanegli Stefan Egli
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: