You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@sling.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2014/10/21 11:32:37 UTC
Build failed in Jenkins: sling-trunk-1.8 » Apache Sling Resource-Based Discovery Service #336
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
Jenkins build is back to normal : sling-trunk-1.8 » Apache Sling Resource-Based Discovery Service #337
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/sling-trunk-1.8/org.apache.sling$org.apache.sling.discovery.impl/337/>