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
