See <https://builds.apache.org/job/sling-trunk-1.8/org.apache.sling$org.apache.sling.discovery.impl/336/>
------------------------------------------ [...truncated 922 lines...] 21.10.2014 09:03:09 *INFO * [main] Instance: /clusterInstances -- jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder 21.10.2014 09:03:09 *INFO * [main] Instance: /78ff998d-3280-48ad-890a-ddb6c0012ae6 -- runtimeId=eec5fb80-c01a-4a90-8b6e-6fe8d22c296f lastHeartbeat=Tue Oct 21 09:03:09 UTC 2014 sling:resourceType=sling:Folder jcr:primaryType=<unknown type=7/> leaderElectionId=0_0000001413882189227_78ff998d-3280-48ad-890a-ddb6c0012ae6 21.10.2014 09:03:09 *INFO * [main] Instance: /properties -- jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder 21.10.2014 09:03:09 *INFO * [main] Instance: /7e5270e5-ca95-42df-a2fa-f44f099cd6d0 -- runtimeId=c078d3f6-8890-4446-9fac-824d01bccbac lastHeartbeat=Tue Oct 21 09:03:09 UTC 2014 sling:resourceType=sling:Folder jcr:primaryType=<unknown type=7/> leaderElectionId=0_0000001413882189292_7e5270e5-ca95-42df-a2fa-f44f099cd6d0 21.10.2014 09:03:09 *INFO * [main] Instance: /properties -- jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder 21.10.2014 09:03:09 *INFO * [main] Instance: /ongoingVotings -- jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder 21.10.2014 09:03:09 *INFO * [main] Instance: /previousView -- jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder 21.10.2014 09:03:09 *INFO * [main] Instance: /establishedView -- jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder 21.10.2014 09:03:09 *INFO * [main] Instance: /0720d8d5-2fc3-48f0-944d-978b7de05d0f -- clusterId=0720d8d5-2fc3-48f0-944d-978b7de05d0f promotedAt=Tue Oct 21 09:03:09 UTC 2014 promotedBy=78ff998d-3280-48ad-890a-ddb6c0012ae6 leaderId=78ff998d-3280-48ad-890a-ddb6c0012ae6 clusterIdDefinedBy=78ff998d-3280-48ad-890a-ddb6c0012ae6 sling:resourceType=sling:Folder votingStart=Tue Oct 21 09:03:09 UTC 2014 clusterIdDefinedAt=Tue Oct 21 09:03:09 UTC 2014 jcr:primaryType=<unknown type=7/> leaderElectionId=0_0000001413882189227_78ff998d-3280-48ad-890a-ddb6c0012ae6 21.10.2014 09:03:09 *INFO * [main] Instance: /members -- jcr:primaryType=<unknown type=7/> 21.10.2014 09:03:09 *INFO * [main] Instance: /78ff998d-3280-48ad-890a-ddb6c0012ae6 -- initiator=true jcr:primaryType=<unknown type=7/> leaderElectionId=0_0000001413882189227_78ff998d-3280-48ad-890a-ddb6c0012ae6 21.10.2014 09:03:09 *INFO * [main] Instance: /7e5270e5-ca95-42df-a2fa-f44f099cd6d0 -- vote=true jcr:primaryType=<unknown type=7/> leaderElectionId=0_0000001413882189292_7e5270e5-ca95-42df-a2fa-f44f099cd6d0 21.10.2014 09:03:09 *INFO * [main] Instance: dumpRepo: ====== END ===== 21.10.2014 09:03:09 *INFO * [main] ClusterTest: testAdditionalInstance: 1st 2s sleep 21.10.2014 09:03:11 *INFO * [main] Instance: Instance [78ff998d-3280-48ad-890a-ddb6c0012ae6] issues a heartbeat now Tue Oct 21 09:03:11 UTC 2014 21.10.2014 09:03:11 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:11 *INFO * [main] Instance: Instance [7e5270e5-ca95-42df-a2fa-f44f099cd6d0] issues a heartbeat now Tue Oct 21 09:03:11 UTC 2014 21.10.2014 09:03:11 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:11 *INFO * [main] ClusterTest: testAdditionalInstance: 2nd 2s sleep 21.10.2014 09:03:12 *INFO * [pool-1-thread-2] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:12 *INFO * [pool-1-thread-1] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:13 *INFO * [main] Instance: dumpRepo: ====== START ===== 21.10.2014 09:03:13 *INFO * [main] Instance: dumpRepo: repo = org.apache.jackrabbit.core.RepositoryImpl@75961f16 21.10.2014 09:03:13 *INFO * [main] Instance: / -- jcr:mixinTypes=<unknown type=7/> jcr:primaryType=<unknown type=7/> 21.10.2014 09:03:13 *INFO * [main] Instance: /var -- jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder 21.10.2014 09:03:13 *INFO * [main] Instance: /discovery -- jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder 21.10.2014 09:03:13 *INFO * [main] Instance: /impl -- jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder 21.10.2014 09:03:13 *INFO * [main] Instance: /clusterInstances -- jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder 21.10.2014 09:03:13 *INFO * [main] Instance: /78ff998d-3280-48ad-890a-ddb6c0012ae6 -- runtimeId=eec5fb80-c01a-4a90-8b6e-6fe8d22c296f lastHeartbeat=Tue Oct 21 09:03:12 UTC 2014 sling:resourceType=sling:Folder jcr:primaryType=<unknown type=7/> leaderElectionId=0_0000001413882189227_78ff998d-3280-48ad-890a-ddb6c0012ae6 21.10.2014 09:03:13 *INFO * [main] Instance: /properties -- jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder 21.10.2014 09:03:13 *INFO * [main] Instance: /7e5270e5-ca95-42df-a2fa-f44f099cd6d0 -- runtimeId=c078d3f6-8890-4446-9fac-824d01bccbac lastHeartbeat=Tue Oct 21 09:03:12 UTC 2014 sling:resourceType=sling:Folder jcr:primaryType=<unknown type=7/> leaderElectionId=0_0000001413882189292_7e5270e5-ca95-42df-a2fa-f44f099cd6d0 21.10.2014 09:03:13 *INFO * [main] Instance: /properties -- jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder 21.10.2014 09:03:13 *INFO * [main] Instance: /ongoingVotings -- jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder 21.10.2014 09:03:13 *INFO * [main] Instance: /previousView -- jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder 21.10.2014 09:03:13 *INFO * [main] Instance: /establishedView -- jcr:primaryType=<unknown type=7/> sling:resourceType=sling:Folder 21.10.2014 09:03:13 *INFO * [main] Instance: /0720d8d5-2fc3-48f0-944d-978b7de05d0f -- clusterId=0720d8d5-2fc3-48f0-944d-978b7de05d0f promotedAt=Tue Oct 21 09:03:09 UTC 2014 promotedBy=78ff998d-3280-48ad-890a-ddb6c0012ae6 leaderId=78ff998d-3280-48ad-890a-ddb6c0012ae6 clusterIdDefinedBy=78ff998d-3280-48ad-890a-ddb6c0012ae6 sling:resourceType=sling:Folder votingStart=Tue Oct 21 09:03:09 UTC 2014 clusterIdDefinedAt=Tue Oct 21 09:03:09 UTC 2014 jcr:primaryType=<unknown type=7/> leaderElectionId=0_0000001413882189227_78ff998d-3280-48ad-890a-ddb6c0012ae6 21.10.2014 09:03:13 *INFO * [main] Instance: /members -- jcr:primaryType=<unknown type=7/> 21.10.2014 09:03:13 *INFO * [main] Instance: /78ff998d-3280-48ad-890a-ddb6c0012ae6 -- initiator=true jcr:primaryType=<unknown type=7/> leaderElectionId=0_0000001413882189227_78ff998d-3280-48ad-890a-ddb6c0012ae6 21.10.2014 09:03:13 *INFO * [main] Instance: /7e5270e5-ca95-42df-a2fa-f44f099cd6d0 -- vote=true jcr:primaryType=<unknown type=7/> leaderElectionId=0_0000001413882189292_7e5270e5-ca95-42df-a2fa-f44f099cd6d0 21.10.2014 09:03:13 *INFO * [main] Instance: dumpRepo: ====== END ===== 21.10.2014 09:03:13 *INFO * [main] ClusterTest: clusterId1=0720d8d5-2fc3-48f0-944d-978b7de05d0f 21.10.2014 09:03:13 *INFO * [main] ClusterTest: clusterId2=0720d8d5-2fc3-48f0-944d-978b7de05d0f 21.10.2014 09:03:13 *INFO * [main] Instance: <init>: starting slingId=02e002f3-619e-4faa-94ca-9882ba320845, debugName=thirdInstance 21.10.2014 09:03:13 *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! 21.10.2014 09:03:13 *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! 21.10.2014 09:03:13 *INFO * [main] Instance: Instance [78ff998d-3280-48ad-890a-ddb6c0012ae6] issues a heartbeat now Tue Oct 21 09:03:13 UTC 2014 21.10.2014 09:03:13 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:13 *INFO * [main] Instance: Instance [7e5270e5-ca95-42df-a2fa-f44f099cd6d0] issues a heartbeat now Tue Oct 21 09:03:13 UTC 2014 21.10.2014 09:03:13 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:13 *INFO * [main] Instance: Instance [02e002f3-619e-4faa-94ca-9882ba320845] issues a heartbeat now Tue Oct 21 09:03:13 UTC 2014 21.10.2014 09:03:13 *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! 21.10.2014 09:03:13 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:13 *INFO * [main] ClusterTest: testAdditionalInstance: 3rd 2s sleep 21.10.2014 09:03:15 *INFO * [main] Instance: Instance [78ff998d-3280-48ad-890a-ddb6c0012ae6] issues a heartbeat now Tue Oct 21 09:03:15 UTC 2014 21.10.2014 09:03:15 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:15 *INFO * [main] Instance: Instance [7e5270e5-ca95-42df-a2fa-f44f099cd6d0] issues a heartbeat now Tue Oct 21 09:03:15 UTC 2014 21.10.2014 09:03:15 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:15 *INFO * [main] Instance: Instance [02e002f3-619e-4faa-94ca-9882ba320845] issues a heartbeat now Tue Oct 21 09:03:15 UTC 2014 21.10.2014 09:03:15 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:15 *INFO * [main] ClusterTest: testAdditionalInstance: 4th 2s sleep 21.10.2014 09:03:16 *INFO * [pool-1-thread-2] HeartbeatHandler: triggerHeartbeat: Could not trigger heartbeat: org.quartz.ObjectAlreadyExistsException: Unable to store Job : 'DEFAULT.org.apache.sling.discovery.impl.common.heartbeat.HeartbeatHandler', because one already exists with this identification. 21.10.2014 09:03:16 *INFO * [pool-1-thread-5] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:16 *INFO * [pool-1-thread-1] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:17 *INFO * [main] ClusterTest: testAdditionalInstance: end 21.10.2014 09:03:17 *INFO * [main] Instance: stop: stopping slingId=02e002f3-619e-4faa-94ca-9882ba320845, debugName=thirdInstance 21.10.2014 09:03:17 *INFO * [main] Instance: stop: removing listener for slingId=02e002f3-619e-4faa-94ca-9882ba320845: org.apache.sling.discovery.impl.setup.Instance$1@5c945ee7 21.10.2014 09:03:17 *INFO * [main] Instance: stop: stopped slingId=02e002f3-619e-4faa-94ca-9882ba320845, debugName=thirdInstance 21.10.2014 09:03:17 *INFO * [main] Instance: stop: stopping slingId=7e5270e5-ca95-42df-a2fa-f44f099cd6d0, debugName=secondInstance 21.10.2014 09:03:17 *INFO * [main] Instance: stop: removing listener for slingId=7e5270e5-ca95-42df-a2fa-f44f099cd6d0: org.apache.sling.discovery.impl.setup.Instance$1@3c2f310c 21.10.2014 09:03:17 *INFO * [main] Instance: stop: stopped slingId=7e5270e5-ca95-42df-a2fa-f44f099cd6d0, debugName=secondInstance 21.10.2014 09:03:17 *INFO * [main] Instance: stop: stopping slingId=78ff998d-3280-48ad-890a-ddb6c0012ae6, debugName=firstInstance 21.10.2014 09:03:17 *INFO * [main] Instance: stop: removing listener for slingId=78ff998d-3280-48ad-890a-ddb6c0012ae6: org.apache.sling.discovery.impl.setup.Instance$1@18301763 21.10.2014 09:03:17 *INFO * [main] Instance: stop: stopped slingId=78ff998d-3280-48ad-890a-ddb6c0012ae6, debugName=firstInstance 21.10.2014 09:03:17 *INFO * [main] Instance: <init>: starting slingId=306875b1-a2cf-4baa-8ae7-861c810ac132, debugName=firstInstance 21.10.2014 09:03:17 *INFO * [ObservationManager] VotingHelper: getWinningVoting: no ongoing votings parent resource found 21.10.2014 09:03:17 *INFO * [ObservationManager] VotingHelper: listOpenNonWinningVotings: no ongoing votings parent resource found 21.10.2014 09:03:18 *INFO * [main] Instance: <init>: starting slingId=0d347011-a004-4991-b9bf-fa0afb122ac0, debugName=secondInstance 21.10.2014 09:03:18 *INFO * [main] ClusterTest: testLeaderAsc: start 21.10.2014 09:03:18 *INFO * [main] ClusterTest: doTestLeader(000,111): start 21.10.2014 09:03:18 *INFO * [main] Instance: stop: stopping slingId=0d347011-a004-4991-b9bf-fa0afb122ac0, debugName=secondInstance 21.10.2014 09:03:18 *INFO * [main] Instance: stop: removing listener for slingId=0d347011-a004-4991-b9bf-fa0afb122ac0: org.apache.sling.discovery.impl.setup.Instance$1@5c648e38 21.10.2014 09:03:18 *INFO * [main] Instance: stop: stopped slingId=0d347011-a004-4991-b9bf-fa0afb122ac0, debugName=secondInstance 21.10.2014 09:03:18 *INFO * [main] Instance: stop: stopping slingId=306875b1-a2cf-4baa-8ae7-861c810ac132, debugName=firstInstance 21.10.2014 09:03:18 *INFO * [main] Instance: stop: removing listener for slingId=306875b1-a2cf-4baa-8ae7-861c810ac132: org.apache.sling.discovery.impl.setup.Instance$1@208b8425 21.10.2014 09:03:18 *INFO * [main] Instance: stop: stopped slingId=306875b1-a2cf-4baa-8ae7-861c810ac132, debugName=firstInstance 21.10.2014 09:03:18 *INFO * [main] Instance: <init>: starting slingId=000, debugName=firstInstance 21.10.2014 09:03:18 *INFO * [main] ClusterTest: doTestLeader: 1st sleep 200ms 21.10.2014 09:03:18 *INFO * [main] Instance: <init>: starting slingId=111, debugName=secondInstance 21.10.2014 09:03:18 *INFO * [main] Instance: Instance [000] issues a heartbeat now Tue Oct 21 09:03:18 UTC 2014 21.10.2014 09:03:18 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:18 *INFO * [main] VotingHelper: getWinningVoting: no ongoing votings parent resource found 21.10.2014 09:03:18 *INFO * [main] VotingHelper: listOpenNonWinningVotings: no ongoing votings parent resource found 21.10.2014 09:03:18 *INFO * [main] Instance: Instance [111] issues a heartbeat now Tue Oct 21 09:03:18 UTC 2014 21.10.2014 09:03:18 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:18 *INFO * [main] ClusterTest: doTestLeader: 2nd sleep 500ms 21.10.2014 09:03:19 *INFO * [main] Instance: Instance [000] issues a heartbeat now Tue Oct 21 09:03:19 UTC 2014 21.10.2014 09:03:19 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:19 *INFO * [main] Instance: Instance [111] issues a heartbeat now Tue Oct 21 09:03:19 UTC 2014 21.10.2014 09:03:19 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:19 *INFO * [main] ClusterTest: doTestLeader: 3rd sleep 500ms 21.10.2014 09:03:19 *INFO * [main] Instance: Instance [000] issues a heartbeat now Tue Oct 21 09:03:19 UTC 2014 21.10.2014 09:03:19 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:19 *INFO * [main] Instance: Instance [111] issues a heartbeat now Tue Oct 21 09:03:19 UTC 2014 21.10.2014 09:03:19 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:19 *INFO * [main] ClusterTest: doTestLeader(000,111): end 21.10.2014 09:03:19 *INFO * [main] ClusterTest: testLeaderAsc: end 21.10.2014 09:03:19 *INFO * [main] Instance: stop: stopping slingId=111, debugName=secondInstance 21.10.2014 09:03:19 *INFO * [main] Instance: stop: removing listener for slingId=111: org.apache.sling.discovery.impl.setup.Instance$1@5fb0a09e 21.10.2014 09:03:19 *INFO * [main] Instance: stop: stopped slingId=111, debugName=secondInstance 21.10.2014 09:03:19 *INFO * [main] Instance: stop: stopping slingId=000, debugName=firstInstance 21.10.2014 09:03:19 *INFO * [main] Instance: stop: removing listener for slingId=000: org.apache.sling.discovery.impl.setup.Instance$1@53b83897 21.10.2014 09:03:19 *INFO * [main] Instance: stop: stopped slingId=000, debugName=firstInstance Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 26.531 sec - in org.apache.sling.discovery.impl.cluster.ClusterTest Running org.apache.sling.discovery.impl.cluster.ClusterLoadTest 21.10.2014 09:03:19 *INFO * [main] ClusterLoadTest: doTest(6,9): muting log output... 21.10.2014 09:03:42 *INFO * [Test-Heartbeat-Runner] TransientRepository: Session opened 21.10.2014 09:03:42 *INFO * [main] ClusterLoadTest: doTest(6,9): not writing muted log output due to success... 21.10.2014 09:03:42 *INFO * [main] ClusterLoadTest: doTest(6,9): unmuted log output. 21.10.2014 09:03:42 *INFO * [main] Instance: stop: stopping slingId=07d576cf-300e-4765-a013-a6bd5fdb533b, debugName=firstInstance 21.10.2014 09:03:42 *INFO * [main] Instance: Stopping Instance [07d576cf-300e-4765-a013-a6bd5fdb533b] 21.10.2014 09:03:42 *INFO * [main] Instance: stop: removing listener for slingId=07d576cf-300e-4765-a013-a6bd5fdb533b: org.apache.sling.discovery.impl.setup.Instance$1@cfe72b0 21.10.2014 09:03:42 *INFO * [Test-Heartbeat-Runner] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:42 *INFO * [Test-Heartbeat-Runner] HeartbeatHandler: triggerHeartbeat: Could not trigger heartbeat: org.quartz.ObjectAlreadyExistsException: Unable to store Job : 'DEFAULT.org.apache.sling.discovery.impl.common.heartbeat.HeartbeatHandler', because one already exists with this identification. 21.10.2014 09:03:42 *INFO * [Test-Heartbeat-Runner] 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! 21.10.2014 09:03:42 *INFO * [Test-Heartbeat-Runner] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:42 *INFO * [main] Instance: stop: stopped slingId=07d576cf-300e-4765-a013-a6bd5fdb533b, debugName=firstInstance 21.10.2014 09:03:42 *INFO * [main] Instance: stop: stopping slingId=5dd530a6-8fcf-4de4-8855-62f599b2caf7, debugName=subsequentInstance-1 21.10.2014 09:03:42 *INFO * [main] Instance: stop: removing listener for slingId=5dd530a6-8fcf-4de4-8855-62f599b2caf7: org.apache.sling.discovery.impl.setup.Instance$1@70a8654 21.10.2014 09:03:42 *INFO * [main] Instance: stop: stopped slingId=5dd530a6-8fcf-4de4-8855-62f599b2caf7, debugName=subsequentInstance-1 21.10.2014 09:03:42 *INFO * [main] Instance: stop: stopping slingId=55c63589-d7c1-4d3e-ad6f-bf9bcddc628d, debugName=subsequentInstance-2 21.10.2014 09:03:42 *INFO * [main] Instance: stop: removing listener for slingId=55c63589-d7c1-4d3e-ad6f-bf9bcddc628d: org.apache.sling.discovery.impl.setup.Instance$1@60660d21 21.10.2014 09:03:42 *INFO * [main] Instance: stop: stopped slingId=55c63589-d7c1-4d3e-ad6f-bf9bcddc628d, debugName=subsequentInstance-2 21.10.2014 09:03:42 *INFO * [main] Instance: stop: stopping slingId=3743fd6a-3737-44b5-aec7-d12a64ef70ce, debugName=subsequentInstance-3 21.10.2014 09:03:42 *INFO * [main] Instance: Stopping Instance [3743fd6a-3737-44b5-aec7-d12a64ef70ce] 21.10.2014 09:03:42 *INFO * [main] Instance: stop: removing listener for slingId=3743fd6a-3737-44b5-aec7-d12a64ef70ce: org.apache.sling.discovery.impl.setup.Instance$1@6d3a56ea 21.10.2014 09:03:42 *INFO * [pool-1-thread-1] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:03:42 *INFO * [main] Instance: stop: stopped slingId=3743fd6a-3737-44b5-aec7-d12a64ef70ce, debugName=subsequentInstance-3 21.10.2014 09:03:42 *INFO * [main] Instance: stop: stopping slingId=a87b6f1f-0ddc-466a-9f1f-54344d06bee2, debugName=subsequentInstance-4 21.10.2014 09:03:42 *INFO * [main] Instance: stop: removing listener for slingId=a87b6f1f-0ddc-466a-9f1f-54344d06bee2: org.apache.sling.discovery.impl.setup.Instance$1@56ece9c 21.10.2014 09:03:42 *INFO * [main] Instance: stop: stopped slingId=a87b6f1f-0ddc-466a-9f1f-54344d06bee2, debugName=subsequentInstance-4 21.10.2014 09:03:42 *INFO * [main] Instance: stop: stopping slingId=0eb01d09-c7a7-430a-afa4-2b3fc007ab23, debugName=subsequentInstance-5 21.10.2014 09:03:42 *INFO * [main] Instance: stop: removing listener for slingId=0eb01d09-c7a7-430a-afa4-2b3fc007ab23: org.apache.sling.discovery.impl.setup.Instance$1@74b13aa 21.10.2014 09:03:42 *INFO * [main] Instance: stop: stopped slingId=0eb01d09-c7a7-430a-afa4-2b3fc007ab23, debugName=subsequentInstance-5 21.10.2014 09:03:42 *INFO * [main] ClusterLoadTest: doTest(3,6): muting log output... 21.10.2014 09:03:46 *INFO * [main] ClusterLoadTest: doTest(3,6): not writing muted log output due to success... 21.10.2014 09:03:46 *INFO * [main] ClusterLoadTest: doTest(3,6): unmuted log output. 21.10.2014 09:03:46 *INFO * [main] Instance: stop: stopping slingId=bba6b589-9d20-465d-a5aa-8a3d6f123a1d, debugName=firstInstance 21.10.2014 09:03:46 *INFO * [main] Instance: stop: removing listener for slingId=bba6b589-9d20-465d-a5aa-8a3d6f123a1d: org.apache.sling.discovery.impl.setup.Instance$1@10fa270e log4j:WARN No appenders could be found for logger (org.apache.sling.discovery.impl.cluster.voting.VotingHandler.6af98de4-4098-4c51-9d20-d3b0b6481088). log4j:WARN Please initialize the log4j system properly. 21.10.2014 09:03:46 *INFO * [main] Instance: stop: stopped slingId=bba6b589-9d20-465d-a5aa-8a3d6f123a1d, debugName=firstInstance 21.10.2014 09:03:46 *INFO * [main] Instance: stop: stopping slingId=85a716b4-e434-4007-a67c-3716392ca6e5, debugName=subsequentInstance-1 21.10.2014 09:03:46 *INFO * [main] Instance: stop: removing listener for slingId=85a716b4-e434-4007-a67c-3716392ca6e5: org.apache.sling.discovery.impl.setup.Instance$1@27103726 21.10.2014 09:03:46 *INFO * [main] Instance: stop: stopped slingId=85a716b4-e434-4007-a67c-3716392ca6e5, debugName=subsequentInstance-1 21.10.2014 09:03:46 *INFO * [main] Instance: stop: stopping slingId=6af98de4-4098-4c51-9d20-d3b0b6481088, debugName=subsequentInstance-2 21.10.2014 09:03:46 *INFO * [main] Instance: Stopping Instance [6af98de4-4098-4c51-9d20-d3b0b6481088] 21.10.2014 09:03:46 *INFO * [main] Instance: stop: removing listener for slingId=6af98de4-4098-4c51-9d20-d3b0b6481088: org.apache.sling.discovery.impl.setup.Instance$1@42000298 21.10.2014 09:03:46 *INFO * [main] Instance: stop: stopped slingId=6af98de4-4098-4c51-9d20-d3b0b6481088, debugName=subsequentInstance-2 21.10.2014 09:03:46 *INFO * [main] ClusterLoadTest: doTest(7,10): muting log output... 21.10.2014 09:04:11 *INFO * [main] ClusterLoadTest: doTest(7,10): not writing muted log output due to success... 21.10.2014 09:04:11 *INFO * [main] ClusterLoadTest: doTest(7,10): unmuted log output. 21.10.2014 09:04:11 *INFO * [main] Instance: stop: stopping slingId=59d12347-7697-4f0f-8b7a-fe5cf14f6f20, debugName=firstInstance 21.10.2014 09:04:11 *INFO * [main] Instance: Stopping Instance [59d12347-7697-4f0f-8b7a-fe5cf14f6f20] 21.10.2014 09:04:11 *INFO * [main] Instance: stop: removing listener for slingId=59d12347-7697-4f0f-8b7a-fe5cf14f6f20: org.apache.sling.discovery.impl.setup.Instance$1@4f86cd50 21.10.2014 09:04:11 *INFO * [Test-Heartbeat-Runner] 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! 21.10.2014 09:04:11 *INFO * [main] Instance: stop: stopped slingId=59d12347-7697-4f0f-8b7a-fe5cf14f6f20, debugName=firstInstance 21.10.2014 09:04:11 *INFO * [main] Instance: stop: stopping slingId=4aba8b18-0a16-4a50-8e50-8f022105f1d9, debugName=subsequentInstance-1 21.10.2014 09:04:11 *INFO * [main] Instance: Stopping Instance [4aba8b18-0a16-4a50-8e50-8f022105f1d9] 21.10.2014 09:04:11 *INFO * [main] Instance: stop: removing listener for slingId=4aba8b18-0a16-4a50-8e50-8f022105f1d9: org.apache.sling.discovery.impl.setup.Instance$1@43165282 21.10.2014 09:04:11 *INFO * [Test-Heartbeat-Runner] HeartbeatHandler: triggerHeartbeat: Could not trigger heartbeat: org.quartz.ObjectAlreadyExistsException: Unable to store Job : 'DEFAULT.org.apache.sling.discovery.impl.common.heartbeat.HeartbeatHandler', because one already exists with this identification. 21.10.2014 09:04:11 *INFO * [Test-Heartbeat-Runner] HeartbeatHandler: triggerHeartbeat: Could not trigger heartbeat: org.quartz.ObjectAlreadyExistsException: Unable to store Job : 'DEFAULT.org.apache.sling.discovery.impl.common.heartbeat.HeartbeatHandler', because one already exists with this identification. 21.10.2014 09:04:11 *INFO * [Test-Heartbeat-Runner] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:04:11 *INFO * [main] Instance: stop: stopped slingId=4aba8b18-0a16-4a50-8e50-8f022105f1d9, debugName=subsequentInstance-1 21.10.2014 09:04:11 *INFO * [main] Instance: stop: stopping slingId=2e6f18ad-cd3a-4c37-bf67-7f33d1f4e925, debugName=subsequentInstance-2 21.10.2014 09:04:11 *INFO * [main] Instance: Stopping Instance [2e6f18ad-cd3a-4c37-bf67-7f33d1f4e925] 21.10.2014 09:04:11 *INFO * [main] Instance: stop: removing listener for slingId=2e6f18ad-cd3a-4c37-bf67-7f33d1f4e925: org.apache.sling.discovery.impl.setup.Instance$1@30c96ea9 21.10.2014 09:04:11 *INFO * [main] Instance: stop: stopped slingId=2e6f18ad-cd3a-4c37-bf67-7f33d1f4e925, debugName=subsequentInstance-2 21.10.2014 09:04:11 *INFO * [main] Instance: stop: stopping slingId=11c663a8-e56f-409b-abeb-cada256d8cf2, debugName=subsequentInstance-3 21.10.2014 09:04:11 *INFO * [main] Instance: stop: removing listener for slingId=11c663a8-e56f-409b-abeb-cada256d8cf2: org.apache.sling.discovery.impl.setup.Instance$1@6e863469 21.10.2014 09:04:11 *INFO * [main] Instance: stop: stopped slingId=11c663a8-e56f-409b-abeb-cada256d8cf2, debugName=subsequentInstance-3 21.10.2014 09:04:11 *INFO * [main] Instance: stop: stopping slingId=ab15f53f-8fa7-4cc2-a2bd-e835b6f3e39e, debugName=subsequentInstance-4 21.10.2014 09:04:11 *INFO * [main] Instance: Stopping Instance [ab15f53f-8fa7-4cc2-a2bd-e835b6f3e39e] 21.10.2014 09:04:11 *INFO * [main] Instance: stop: removing listener for slingId=ab15f53f-8fa7-4cc2-a2bd-e835b6f3e39e: org.apache.sling.discovery.impl.setup.Instance$1@42f15e87 21.10.2014 09:04:11 *INFO * [main] Instance: stop: stopped slingId=ab15f53f-8fa7-4cc2-a2bd-e835b6f3e39e, debugName=subsequentInstance-4 21.10.2014 09:04:11 *INFO * [main] Instance: stop: stopping slingId=0541d78f-8aad-49f6-acfb-c131fde03649, debugName=subsequentInstance-5 21.10.2014 09:04:11 *INFO * [main] Instance: stop: removing listener for slingId=0541d78f-8aad-49f6-acfb-c131fde03649: org.apache.sling.discovery.impl.setup.Instance$1@5d685156 21.10.2014 09:04:11 *INFO * [main] Instance: stop: stopped slingId=0541d78f-8aad-49f6-acfb-c131fde03649, debugName=subsequentInstance-5 21.10.2014 09:04:11 *INFO * [main] Instance: stop: stopping slingId=80910eb4-1813-48fe-8b86-f75b58facbd2, debugName=subsequentInstance-6 21.10.2014 09:04:11 *INFO * [main] Instance: stop: removing listener for slingId=80910eb4-1813-48fe-8b86-f75b58facbd2: org.apache.sling.discovery.impl.setup.Instance$1@64903a20 21.10.2014 09:04:11 *INFO * [main] Instance: stop: stopped slingId=80910eb4-1813-48fe-8b86-f75b58facbd2, debugName=subsequentInstance-6 21.10.2014 09:04:11 *INFO * [Test-Heartbeat-Runner] HeartbeatHandler: doCheckView: votingHandler is null! 21.10.2014 09:04:11 *INFO * [main] ClusterLoadTest: doTest(5,8): muting log output... 21.10.2014 09:04:26 *INFO * [main] ClusterLoadTest: doTest(5,8): not writing muted log output due to success... 21.10.2014 09:04:26 *INFO * [main] ClusterLoadTest: doTest(5,8): unmuted log output. 21.10.2014 09:04:26 *INFO * [main] Instance: stop: stopping slingId=d52b0489-5b4f-4b0b-b0fe-a61207fdcd06, debugName=firstInstance 21.10.2014 09:04:26 *INFO * [main] Instance: Stopping Instance [d52b0489-5b4f-4b0b-b0fe-a61207fdcd06] 21.10.2014 09:04:26 *INFO * [main] Instance: stop: removing listener for slingId=d52b0489-5b4f-4b0b-b0fe-a61207fdcd06: org.apache.sling.discovery.impl.setup.Instance$1@3464d24c 21.10.2014 09:04:26 *INFO * [main] Instance: stop: stopped slingId=d52b0489-5b4f-4b0b-b0fe-a61207fdcd06, debugName=firstInstance 21.10.2014 09:04:26 *INFO * [main] Instance: stop: stopping slingId=555ab8a9-0281-40fe-bafc-50a9830d55e1, debugName=subsequentInstance-1 21.10.2014 09:04:26 *INFO * [main] Instance: stop: removing listener for slingId=555ab8a9-0281-40fe-bafc-50a9830d55e1: org.apache.sling.discovery.impl.setup.Instance$1@75eed00f 21.10.2014 09:04:26 *INFO * [main] Instance: stop: stopped slingId=555ab8a9-0281-40fe-bafc-50a9830d55e1, debugName=subsequentInstance-1 21.10.2014 09:04:26 *INFO * [main] Instance: stop: stopping slingId=ac0287af-10e2-45a3-b30d-b372bfc59bd9, debugName=subsequentInstance-2 21.10.2014 09:04:26 *INFO * [main] Instance: stop: removing listener for slingId=ac0287af-10e2-45a3-b30d-b372bfc59bd9: org.apache.sling.discovery.impl.setup.Instance$1@3f32c65f 21.10.2014 09:04:26 *INFO * [main] Instance: stop: stopped slingId=ac0287af-10e2-45a3-b30d-b372bfc59bd9, debugName=subsequentInstance-2 21.10.2014 09:04:26 *INFO * [main] Instance: stop: stopping slingId=ee7b8952-cacb-49a6-a635-96c704e9b8af, debugName=subsequentInstance-3 21.10.2014 09:04:26 *INFO * [main] Instance: stop: removing listener for slingId=ee7b8952-cacb-49a6-a635-96c704e9b8af: org.apache.sling.discovery.impl.setup.Instance$1@53a52b3f 21.10.2014 09:04:26 *INFO * [main] Instance: stop: stopped slingId=ee7b8952-cacb-49a6-a635-96c704e9b8af, debugName=subsequentInstance-3 21.10.2014 09:04:26 *INFO * [main] Instance: stop: stopping slingId=0c75cdf3-1624-4739-9aeb-677579fcaf08, debugName=subsequentInstance-4 21.10.2014 09:04:26 *INFO * [main] Instance: stop: removing listener for slingId=0c75cdf3-1624-4739-9aeb-677579fcaf08: org.apache.sling.discovery.impl.setup.Instance$1@6f6db08 21.10.2014 09:04:26 *INFO * [main] Instance: stop: stopped slingId=0c75cdf3-1624-4739-9aeb-677579fcaf08, debugName=subsequentInstance-4 21.10.2014 09:04:26 *INFO * [main] ClusterLoadTest: doTest(4,7): muting log output... javax.jcr.PathNotFoundException: /var/discovery/impl/ClusterLoadTest/doTest-4-7/establishedView/5b2a8296-445f-495e-8af8-b8f6a1ffc767 at org.apache.jackrabbit.core.ItemManager.getNode(ItemManager.java:577) at org.apache.jackrabbit.core.session.SessionItemOperation$6.perform(SessionItemOperation.java:129) at org.apache.jackrabbit.core.session.SessionItemOperation$6.perform(SessionItemOperation.java:125) at org.apache.jackrabbit.core.session.SessionItemOperation.perform(SessionItemOperation.java:187) at org.apache.jackrabbit.core.session.SessionState.perform(SessionState.java:200) at org.apache.jackrabbit.core.SessionImpl.perform(SessionImpl.java:355) at org.apache.jackrabbit.core.SessionImpl.getNode(SessionImpl.java:1054) at org.apache.sling.discovery.impl.setup.MockedResource.adaptTo(MockedResource.java:96) at org.apache.sling.discovery.impl.common.resource.EstablishedClusterView.<init>(EstablishedClusterView.java:59) at org.apache.sling.discovery.impl.cluster.ClusterViewServiceImpl.getClusterView(ClusterViewServiceImpl.java:142) at org.apache.sling.discovery.impl.DiscoveryServiceImpl.getTopology(DiscoveryServiceImpl.java:418) at org.apache.sling.discovery.impl.DiscoveryServiceImpl.handlePotentialTopologyChange(DiscoveryServiceImpl.java:466) at org.apache.sling.discovery.impl.DiscoveryServiceImpl.updateProperties(DiscoveryServiceImpl.java:440) at org.apache.sling.discovery.impl.common.heartbeat.HeartbeatHandler.issueHeartbeat(HeartbeatHandler.java:253) at org.apache.sling.discovery.impl.common.heartbeat.HeartbeatHandler.run(HeartbeatHandler.java:209) at org.apache.sling.discovery.impl.setup.Instance.runHeartbeatOnce(Instance.java:487) at org.apache.sling.discovery.impl.setup.Instance$HeartbeatRunner.run(Instance.java:234) at java.lang.Thread.run(Thread.java:745) Exception in thread "Test-Heartbeat-Runner" java.lang.IllegalStateException: valueMap must not be null at org.apache.sling.discovery.impl.common.resource.EstablishedClusterView.<init>(EstablishedClusterView.java:61) at org.apache.sling.discovery.impl.cluster.ClusterViewServiceImpl.getClusterView(ClusterViewServiceImpl.java:142) at org.apache.sling.discovery.impl.DiscoveryServiceImpl.getTopology(DiscoveryServiceImpl.java:418) at org.apache.sling.discovery.impl.DiscoveryServiceImpl.handlePotentialTopologyChange(DiscoveryServiceImpl.java:466) at org.apache.sling.discovery.impl.DiscoveryServiceImpl.updateProperties(DiscoveryServiceImpl.java:440) at org.apache.sling.discovery.impl.common.heartbeat.HeartbeatHandler.issueHeartbeat(HeartbeatHandler.java:253) at org.apache.sling.discovery.impl.common.heartbeat.HeartbeatHandler.run(HeartbeatHandler.java:209) at org.apache.sling.discovery.impl.setup.Instance.runHeartbeatOnce(Instance.java:487) at org.apache.sling.discovery.impl.setup.Instance$HeartbeatRunner.run(Instance.java:234) at java.lang.Thread.run(Thread.java:745) Killed Results : Tests run: 11, Failures: 0, Errors: 0, Skipped: 0 [JENKINS] Recording test results [JENKINS] Archiving disabled