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/07/31 03:21:35 UTC
Build failed in Jenkins: sling-trunk-1.7 » Apache Sling Resource-Based Discovery Service #721
See <https://builds.apache.org/job/sling-trunk-1.7/org.apache.sling$org.apache.sling.discovery.impl/721/>
------------------------------------------
[...truncated 864 lines...]
31.07.2014 01:17:32 *INFO * [main] Instance: Instance [6bad8b59-a89f-45ce-89f1-992816e32d56] issues a heartbeat now Thu Jul 31 01:17:32 UTC 2014
31.07.2014 01:17:32 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:32 *INFO * [main] ClusterTest: testPropertyProviders: 2nd 2s sleep
31.07.2014 01:17:33 *INFO * [pool-1-thread-3] 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.
31.07.2014 01:17:33 *INFO * [pool-1-thread-2] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:33 *INFO * [pool-1-thread-5] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:34 *INFO * [pool-1-thread-1] 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.
31.07.2014 01:17:34 *INFO * [main] 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.
31.07.2014 01:17:34 *INFO * [pool-1-thread-1] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:34 *INFO * [main] Instance: Instance [02577c07-f90c-4c39-8175-2375d50d578a] issues a heartbeat now Thu Jul 31 01:17:34 UTC 2014
31.07.2014 01:17:34 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:34 *INFO * [main] Instance: Instance [3e7f2261-8c4f-410a-a35f-65f22402d087] issues a heartbeat now Thu Jul 31 01:17:34 UTC 2014
31.07.2014 01:17:34 *INFO * [main] 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.
31.07.2014 01:17:34 *INFO * [pool-1-thread-3] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:34 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:34 *INFO * [main] ClusterTest: testPropertyProviders: end
31.07.2014 01:17:34 *INFO * [main] Instance: stop: stopping slingId=6bad8b59-a89f-45ce-89f1-992816e32d56, debugName=thirdInstance
31.07.2014 01:17:34 *INFO * [main] Instance: stop: removing listener for slingId=6bad8b59-a89f-45ce-89f1-992816e32d56: org.apache.sling.discovery.impl.setup.Instance$1@6a1b79
31.07.2014 01:17:34 *INFO * [main] Instance: stop: stopped slingId=6bad8b59-a89f-45ce-89f1-992816e32d56, debugName=thirdInstance
31.07.2014 01:17:34 *INFO * [main] Instance: stop: stopping slingId=3e7f2261-8c4f-410a-a35f-65f22402d087, debugName=secondInstance
31.07.2014 01:17:34 *INFO * [main] Instance: stop: removing listener for slingId=3e7f2261-8c4f-410a-a35f-65f22402d087: org.apache.sling.discovery.impl.setup.Instance$1@18bd0ac
31.07.2014 01:17:34 *INFO * [main] Instance: stop: stopped slingId=3e7f2261-8c4f-410a-a35f-65f22402d087, debugName=secondInstance
31.07.2014 01:17:34 *INFO * [main] Instance: stop: stopping slingId=02577c07-f90c-4c39-8175-2375d50d578a, debugName=firstInstance
31.07.2014 01:17:34 *INFO * [main] Instance: stop: removing listener for slingId=02577c07-f90c-4c39-8175-2375d50d578a: org.apache.sling.discovery.impl.setup.Instance$1@1f1380b
31.07.2014 01:17:34 *INFO * [main] Instance: stop: stopped slingId=02577c07-f90c-4c39-8175-2375d50d578a, debugName=firstInstance
31.07.2014 01:17:34 *INFO * [main] Instance: <init>: starting slingId=c96d031d-166a-49ec-a2ba-b4703e71fdd5, debugName=firstInstance
31.07.2014 01:17:34 *INFO * [ObservationManager] VotingHelper: getWinningVoting: no ongoing votings parent resource found
31.07.2014 01:17:34 *INFO * [ObservationManager] VotingHelper: listOpenNonWinningVotings: no ongoing votings parent resource found
31.07.2014 01:17:34 *INFO * [main] Instance: <init>: starting slingId=d5c2ca5b-32df-4621-a665-fc0f2333d5e8, debugName=secondInstance
31.07.2014 01:17:35 *INFO * [main] ClusterTest: testLeaderDesc: start
31.07.2014 01:17:35 *INFO * [main] ClusterTest: doTestLeader(111,000): start
31.07.2014 01:17:35 *INFO * [main] Instance: stop: stopping slingId=d5c2ca5b-32df-4621-a665-fc0f2333d5e8, debugName=secondInstance
31.07.2014 01:17:35 *INFO * [main] Instance: stop: removing listener for slingId=d5c2ca5b-32df-4621-a665-fc0f2333d5e8: org.apache.sling.discovery.impl.setup.Instance$1@ce81be
31.07.2014 01:17:35 *INFO * [main] Instance: stop: stopped slingId=d5c2ca5b-32df-4621-a665-fc0f2333d5e8, debugName=secondInstance
31.07.2014 01:17:35 *INFO * [main] Instance: stop: stopping slingId=c96d031d-166a-49ec-a2ba-b4703e71fdd5, debugName=firstInstance
31.07.2014 01:17:35 *INFO * [main] Instance: stop: removing listener for slingId=c96d031d-166a-49ec-a2ba-b4703e71fdd5: org.apache.sling.discovery.impl.setup.Instance$1@146e91a
31.07.2014 01:17:35 *INFO * [main] Instance: stop: stopped slingId=c96d031d-166a-49ec-a2ba-b4703e71fdd5, debugName=firstInstance
31.07.2014 01:17:35 *INFO * [main] Instance: <init>: starting slingId=111, debugName=firstInstance
31.07.2014 01:17:35 *INFO * [main] ClusterTest: doTestLeader: 1st sleep 200ms
31.07.2014 01:17:35 *INFO * [main] Instance: <init>: starting slingId=000, debugName=secondInstance
31.07.2014 01:17:35 *INFO * [main] Instance: Instance [111] issues a heartbeat now Thu Jul 31 01:17:35 UTC 2014
31.07.2014 01:17:35 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:35 *INFO * [main] VotingHelper: getWinningVoting: no ongoing votings parent resource found
31.07.2014 01:17:35 *INFO * [main] VotingHelper: listOpenNonWinningVotings: no ongoing votings parent resource found
31.07.2014 01:17:35 *INFO * [main] Instance: Instance [000] issues a heartbeat now Thu Jul 31 01:17:35 UTC 2014
31.07.2014 01:17:35 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:35 *INFO * [main] ClusterTest: doTestLeader: 2nd sleep 500ms
31.07.2014 01:17:35 *INFO * [main] Instance: Instance [111] issues a heartbeat now Thu Jul 31 01:17:35 UTC 2014
31.07.2014 01:17:35 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:35 *INFO * [main] Instance: Instance [000] issues a heartbeat now Thu Jul 31 01:17:35 UTC 2014
31.07.2014 01:17:35 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:35 *INFO * [main] ClusterTest: doTestLeader: 3rd sleep 500ms
31.07.2014 01:17:36 *INFO * [main] Instance: Instance [111] issues a heartbeat now Thu Jul 31 01:17:36 UTC 2014
31.07.2014 01:17:36 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:36 *INFO * [main] Instance: Instance [000] issues a heartbeat now Thu Jul 31 01:17:36 UTC 2014
31.07.2014 01:17:36 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:36 *INFO * [main] ClusterTest: doTestLeader(111,000): end
31.07.2014 01:17:36 *INFO * [main] ClusterTest: testLeaderDesc: end
31.07.2014 01:17:36 *INFO * [main] Instance: stop: stopping slingId=000, debugName=secondInstance
31.07.2014 01:17:36 *INFO * [main] Instance: stop: removing listener for slingId=000: org.apache.sling.discovery.impl.setup.Instance$1@616408
31.07.2014 01:17:36 *INFO * [main] Instance: stop: stopped slingId=000, debugName=secondInstance
31.07.2014 01:17:36 *INFO * [main] Instance: stop: stopping slingId=111, debugName=firstInstance
31.07.2014 01:17:36 *INFO * [main] Instance: stop: removing listener for slingId=111: org.apache.sling.discovery.impl.setup.Instance$1@e807b0
31.07.2014 01:17:36 *INFO * [main] Instance: stop: stopped slingId=111, debugName=firstInstance
31.07.2014 01:17:36 *INFO * [main] Instance: <init>: starting slingId=9bb316d7-513f-422a-a90b-4483bd969105, debugName=firstInstance
31.07.2014 01:17:36 *INFO * [ObservationManager] VotingHelper: getWinningVoting: no ongoing votings parent resource found
31.07.2014 01:17:36 *INFO * [ObservationManager] VotingHelper: listOpenNonWinningVotings: no ongoing votings parent resource found
31.07.2014 01:17:36 *INFO * [main] Instance: <init>: starting slingId=ebfc9e8e-f659-4d89-940d-3ffca1e51277, debugName=secondInstance
31.07.2014 01:17:36 *INFO * [main] ClusterTest: testAdditionalInstance: start
31.07.2014 01:17:36 *INFO * [main] Instance: Instance [9bb316d7-513f-422a-a90b-4483bd969105] issues a heartbeat now Thu Jul 31 01:17:36 UTC 2014
31.07.2014 01:17:36 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:36 *INFO * [main] VotingHelper: getWinningVoting: no ongoing votings parent resource found
31.07.2014 01:17:36 *INFO * [main] VotingHelper: listOpenNonWinningVotings: no ongoing votings parent resource found
31.07.2014 01:17:36 *INFO * [main] Instance: Instance [ebfc9e8e-f659-4d89-940d-3ffca1e51277] issues a heartbeat now Thu Jul 31 01:17:36 UTC 2014
31.07.2014 01:17:36 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:36 *INFO * [main] Instance: dumpRepo: ====== START =====
31.07.2014 01:17:36 *INFO * [main] Instance: dumpRepo: repo = org.apache.jackrabbit.core.RepositoryImpl@1a089b3
31.07.2014 01:17:36 *INFO * [main] Instance: / -- jcr:mixinTypes=<unknown type=7/> jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:36 *INFO * [main] Instance: /var -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:36 *INFO * [main] Instance: /discovery -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:36 *INFO * [main] Instance: /impl -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:36 *INFO * [main] Instance: /clusterInstances -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:36 *INFO * [main] Instance: /9bb316d7-513f-422a-a90b-4483bd969105 -- leaderElectionId=0_0000001406769456435_9bb316d7-513f-422a-a90b-4483bd969105 lastHeartbeat=Thu Jul 31 01:17:36 UTC 2014 jcr:primaryType=<unknown type=7/> runtimeId=da85d455-6c08-4f15-b261-2ccf722ca09b
31.07.2014 01:17:36 *INFO * [main] Instance: /properties -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:36 *INFO * [main] Instance: /ebfc9e8e-f659-4d89-940d-3ffca1e51277 -- leaderElectionId=0_0000001406769456448_ebfc9e8e-f659-4d89-940d-3ffca1e51277 lastHeartbeat=Thu Jul 31 01:17:36 UTC 2014 jcr:primaryType=<unknown type=7/> runtimeId=a04b899b-af4e-4da8-9a6d-e3092eb79976
31.07.2014 01:17:36 *INFO * [main] Instance: /properties -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:36 *INFO * [main] Instance: /ongoingVotings -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:36 *INFO * [main] Instance: /previousView -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:36 *INFO * [main] Instance: /establishedView -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:36 *INFO * [main] Instance: /c495af28-5812-4ff9-8f15-8d5a230577ef -- leaderId=9bb316d7-513f-422a-a90b-4483bd969105 promotedAt=Thu Jul 31 01:17:36 UTC 2014 clusterId=c495af28-5812-4ff9-8f15-8d5a230577ef leaderElectionId=0_0000001406769456435_9bb316d7-513f-422a-a90b-4483bd969105 clusterIdDefinedAt=Thu Jul 31 01:17:36 UTC 2014 votingStart=Thu Jul 31 01:17:36 UTC 2014 promotedBy=9bb316d7-513f-422a-a90b-4483bd969105 clusterIdDefinedBy=9bb316d7-513f-422a-a90b-4483bd969105 jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:36 *INFO * [main] Instance: /members -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:36 *INFO * [main] Instance: /ebfc9e8e-f659-4d89-940d-3ffca1e51277 -- leaderElectionId=0_0000001406769456448_ebfc9e8e-f659-4d89-940d-3ffca1e51277 vote=true jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:36 *INFO * [main] Instance: /9bb316d7-513f-422a-a90b-4483bd969105 -- initiator=true leaderElectionId=0_0000001406769456435_9bb316d7-513f-422a-a90b-4483bd969105 jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:36 *INFO * [main] Instance: dumpRepo: ====== END =====
31.07.2014 01:17:36 *INFO * [main] ClusterTest: testAdditionalInstance: 1st 2s sleep
31.07.2014 01:17:38 *INFO * [main] Instance: Instance [9bb316d7-513f-422a-a90b-4483bd969105] issues a heartbeat now Thu Jul 31 01:17:38 UTC 2014
31.07.2014 01:17:38 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:38 *INFO * [main] Instance: Instance [ebfc9e8e-f659-4d89-940d-3ffca1e51277] issues a heartbeat now Thu Jul 31 01:17:38 UTC 2014
31.07.2014 01:17:38 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:38 *INFO * [main] ClusterTest: testAdditionalInstance: 2nd 2s sleep
31.07.2014 01:17:39 *INFO * [pool-1-thread-1] 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.
31.07.2014 01:17:39 *INFO * [pool-1-thread-3] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:40 *INFO * [main] Instance: dumpRepo: ====== START =====
31.07.2014 01:17:40 *INFO * [main] Instance: dumpRepo: repo = org.apache.jackrabbit.core.RepositoryImpl@1a089b3
31.07.2014 01:17:40 *INFO * [main] Instance: / -- jcr:mixinTypes=<unknown type=7/> jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:40 *INFO * [main] Instance: /var -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:40 *INFO * [main] Instance: /discovery -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:40 *INFO * [main] Instance: /impl -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:40 *INFO * [main] Instance: /clusterInstances -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:40 *INFO * [main] Instance: /9bb316d7-513f-422a-a90b-4483bd969105 -- leaderElectionId=0_0000001406769456435_9bb316d7-513f-422a-a90b-4483bd969105 lastHeartbeat=Thu Jul 31 01:17:39 UTC 2014 jcr:primaryType=<unknown type=7/> runtimeId=da85d455-6c08-4f15-b261-2ccf722ca09b
31.07.2014 01:17:40 *INFO * [main] Instance: /properties -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:40 *INFO * [main] Instance: /ebfc9e8e-f659-4d89-940d-3ffca1e51277 -- leaderElectionId=0_0000001406769456448_ebfc9e8e-f659-4d89-940d-3ffca1e51277 lastHeartbeat=Thu Jul 31 01:17:38 UTC 2014 jcr:primaryType=<unknown type=7/> runtimeId=a04b899b-af4e-4da8-9a6d-e3092eb79976
31.07.2014 01:17:40 *INFO * [main] Instance: /properties -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:40 *INFO * [main] Instance: /ongoingVotings -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:40 *INFO * [main] Instance: /previousView -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:40 *INFO * [main] Instance: /establishedView -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:40 *INFO * [main] Instance: /c495af28-5812-4ff9-8f15-8d5a230577ef -- leaderId=9bb316d7-513f-422a-a90b-4483bd969105 promotedAt=Thu Jul 31 01:17:36 UTC 2014 clusterId=c495af28-5812-4ff9-8f15-8d5a230577ef leaderElectionId=0_0000001406769456435_9bb316d7-513f-422a-a90b-4483bd969105 clusterIdDefinedAt=Thu Jul 31 01:17:36 UTC 2014 votingStart=Thu Jul 31 01:17:36 UTC 2014 promotedBy=9bb316d7-513f-422a-a90b-4483bd969105 clusterIdDefinedBy=9bb316d7-513f-422a-a90b-4483bd969105 jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:40 *INFO * [main] Instance: /members -- jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:40 *INFO * [main] Instance: /ebfc9e8e-f659-4d89-940d-3ffca1e51277 -- leaderElectionId=0_0000001406769456448_ebfc9e8e-f659-4d89-940d-3ffca1e51277 vote=true jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:40 *INFO * [main] Instance: /9bb316d7-513f-422a-a90b-4483bd969105 -- initiator=true leaderElectionId=0_0000001406769456435_9bb316d7-513f-422a-a90b-4483bd969105 jcr:primaryType=<unknown type=7/>
31.07.2014 01:17:40 *INFO * [main] Instance: dumpRepo: ====== END =====
31.07.2014 01:17:40 *INFO * [main] ClusterTest: clusterId1=c495af28-5812-4ff9-8f15-8d5a230577ef
31.07.2014 01:17:40 *INFO * [main] ClusterTest: clusterId2=c495af28-5812-4ff9-8f15-8d5a230577ef
31.07.2014 01:17:40 *INFO * [main] Instance: <init>: starting slingId=a4f77f29-61a8-4c12-9584-f53f9a7f7c11, debugName=thirdInstance
31.07.2014 01:17:40 *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!
31.07.2014 01:17:40 *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!
31.07.2014 01:17:40 *INFO * [main] Instance: Instance [9bb316d7-513f-422a-a90b-4483bd969105] issues a heartbeat now Thu Jul 31 01:17:40 UTC 2014
31.07.2014 01:17:40 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:40 *INFO * [main] Instance: Instance [ebfc9e8e-f659-4d89-940d-3ffca1e51277] issues a heartbeat now Thu Jul 31 01:17:40 UTC 2014
31.07.2014 01:17:40 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:40 *INFO * [main] Instance: Instance [a4f77f29-61a8-4c12-9584-f53f9a7f7c11] issues a heartbeat now Thu Jul 31 01:17:40 UTC 2014
31.07.2014 01:17:40 *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!
31.07.2014 01:17:40 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:40 *INFO * [main] ClusterTest: testAdditionalInstance: 3rd 2s sleep
31.07.2014 01:17:42 *INFO * [main] Instance: Instance [9bb316d7-513f-422a-a90b-4483bd969105] issues a heartbeat now Thu Jul 31 01:17:42 UTC 2014
31.07.2014 01:17:42 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:42 *INFO * [main] Instance: Instance [ebfc9e8e-f659-4d89-940d-3ffca1e51277] issues a heartbeat now Thu Jul 31 01:17:42 UTC 2014
31.07.2014 01:17:42 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:42 *INFO * [main] Instance: Instance [a4f77f29-61a8-4c12-9584-f53f9a7f7c11] issues a heartbeat now Thu Jul 31 01:17:42 UTC 2014
31.07.2014 01:17:42 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:42 *INFO * [main] ClusterTest: testAdditionalInstance: 4th 2s sleep
31.07.2014 01:17:43 *INFO * [pool-1-thread-4] 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.
31.07.2014 01:17:43 *INFO * [pool-1-thread-5] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:43 *INFO * [pool-1-thread-3] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:44 *INFO * [main] ClusterTest: testAdditionalInstance: end
31.07.2014 01:17:44 *INFO * [main] Instance: stop: stopping slingId=a4f77f29-61a8-4c12-9584-f53f9a7f7c11, debugName=thirdInstance
31.07.2014 01:17:44 *INFO * [main] Instance: stop: removing listener for slingId=a4f77f29-61a8-4c12-9584-f53f9a7f7c11: org.apache.sling.discovery.impl.setup.Instance$1@f073b3
31.07.2014 01:17:44 *INFO * [main] Instance: stop: stopped slingId=a4f77f29-61a8-4c12-9584-f53f9a7f7c11, debugName=thirdInstance
31.07.2014 01:17:44 *INFO * [main] Instance: stop: stopping slingId=ebfc9e8e-f659-4d89-940d-3ffca1e51277, debugName=secondInstance
31.07.2014 01:17:44 *INFO * [main] Instance: stop: removing listener for slingId=ebfc9e8e-f659-4d89-940d-3ffca1e51277: org.apache.sling.discovery.impl.setup.Instance$1@6c7f1f
31.07.2014 01:17:44 *INFO * [main] Instance: stop: stopped slingId=ebfc9e8e-f659-4d89-940d-3ffca1e51277, debugName=secondInstance
31.07.2014 01:17:44 *INFO * [main] Instance: stop: stopping slingId=9bb316d7-513f-422a-a90b-4483bd969105, debugName=firstInstance
31.07.2014 01:17:44 *INFO * [main] Instance: stop: removing listener for slingId=9bb316d7-513f-422a-a90b-4483bd969105: org.apache.sling.discovery.impl.setup.Instance$1@1cf91a1
31.07.2014 01:17:44 *INFO * [main] Instance: stop: stopped slingId=9bb316d7-513f-422a-a90b-4483bd969105, debugName=firstInstance
31.07.2014 01:17:44 *INFO * [main] Instance: <init>: starting slingId=3fcde2b1-af9a-4271-90c2-686a81d863ed, debugName=firstInstance
31.07.2014 01:17:44 *INFO * [ObservationManager] VotingHelper: getWinningVoting: no ongoing votings parent resource found
31.07.2014 01:17:44 *INFO * [ObservationManager] VotingHelper: listOpenNonWinningVotings: no ongoing votings parent resource found
31.07.2014 01:17:44 *INFO * [main] Instance: <init>: starting slingId=3bbee211-4478-4499-b6e3-d5e1220f4069, debugName=secondInstance
31.07.2014 01:17:44 *INFO * [main] ClusterTest: testLeaderAsc: start
31.07.2014 01:17:44 *INFO * [main] ClusterTest: doTestLeader(000,111): start
31.07.2014 01:17:44 *INFO * [main] Instance: stop: stopping slingId=3bbee211-4478-4499-b6e3-d5e1220f4069, debugName=secondInstance
31.07.2014 01:17:44 *INFO * [main] Instance: stop: removing listener for slingId=3bbee211-4478-4499-b6e3-d5e1220f4069: org.apache.sling.discovery.impl.setup.Instance$1@11aacdb
31.07.2014 01:17:44 *INFO * [main] Instance: stop: stopped slingId=3bbee211-4478-4499-b6e3-d5e1220f4069, debugName=secondInstance
31.07.2014 01:17:44 *INFO * [main] Instance: stop: stopping slingId=3fcde2b1-af9a-4271-90c2-686a81d863ed, debugName=firstInstance
31.07.2014 01:17:44 *INFO * [main] Instance: stop: removing listener for slingId=3fcde2b1-af9a-4271-90c2-686a81d863ed: org.apache.sling.discovery.impl.setup.Instance$1@1b4108a
31.07.2014 01:17:44 *INFO * [main] Instance: stop: stopped slingId=3fcde2b1-af9a-4271-90c2-686a81d863ed, debugName=firstInstance
31.07.2014 01:17:44 *INFO * [main] Instance: <init>: starting slingId=000, debugName=firstInstance
31.07.2014 01:17:44 *INFO * [main] ClusterTest: doTestLeader: 1st sleep 200ms
31.07.2014 01:17:44 *INFO * [main] Instance: <init>: starting slingId=111, debugName=secondInstance
31.07.2014 01:17:44 *INFO * [main] Instance: Instance [000] issues a heartbeat now Thu Jul 31 01:17:44 UTC 2014
31.07.2014 01:17:44 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:44 *INFO * [main] VotingHelper: getWinningVoting: no ongoing votings parent resource found
31.07.2014 01:17:44 *INFO * [main] VotingHelper: listOpenNonWinningVotings: no ongoing votings parent resource found
31.07.2014 01:17:45 *WARN * [main] ItemStateReferenceCache: overwriting cached entry 759323d5-7724-4d97-bb66-f7e114a970d0/{}clusterId
31.07.2014 01:17:45 *WARN * [main] ItemStateReferenceCache: overwriting cached entry 759323d5-7724-4d97-bb66-f7e114a970d0/{}clusterIdDefinedBy
31.07.2014 01:17:45 *WARN * [main] ItemStateReferenceCache: overwriting cached entry 759323d5-7724-4d97-bb66-f7e114a970d0/{}votingStart
31.07.2014 01:17:45 *WARN * [ObservationManager] ItemStateReferenceCache: overwriting cached entry a4020dec-7a7d-49af-8f8a-0532c46b78b8
31.07.2014 01:17:45 *INFO * [main] Instance: Instance [111] issues a heartbeat now Thu Jul 31 01:17:45 UTC 2014
31.07.2014 01:17:45 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:45 *INFO * [main] ClusterTest: doTestLeader: 2nd sleep 500ms
31.07.2014 01:17:45 *INFO * [main] Instance: Instance [000] issues a heartbeat now Thu Jul 31 01:17:45 UTC 2014
31.07.2014 01:17:45 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:45 *INFO * [main] Instance: Instance [111] issues a heartbeat now Thu Jul 31 01:17:45 UTC 2014
31.07.2014 01:17:45 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:45 *INFO * [main] ClusterTest: doTestLeader: 3rd sleep 500ms
31.07.2014 01:17:46 *INFO * [main] Instance: Instance [000] issues a heartbeat now Thu Jul 31 01:17:46 UTC 2014
31.07.2014 01:17:46 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:46 *INFO * [main] Instance: Instance [111] issues a heartbeat now Thu Jul 31 01:17:46 UTC 2014
31.07.2014 01:17:46 *INFO * [main] HeartbeatHandler: doCheckView: votingHandler is null!
31.07.2014 01:17:46 *INFO * [main] ClusterTest: doTestLeader(000,111): end
31.07.2014 01:17:46 *INFO * [main] ClusterTest: testLeaderAsc: end
31.07.2014 01:17:46 *INFO * [main] Instance: stop: stopping slingId=111, debugName=secondInstance
31.07.2014 01:17:46 *INFO * [main] Instance: stop: removing listener for slingId=111: org.apache.sling.discovery.impl.setup.Instance$1@1949f78
31.07.2014 01:17:46 *INFO * [main] Instance: stop: stopped slingId=111, debugName=secondInstance
31.07.2014 01:17:46 *INFO * [main] Instance: stop: stopping slingId=000, debugName=firstInstance
31.07.2014 01:17:46 *INFO * [main] Instance: stop: removing listener for slingId=000: org.apache.sling.discovery.impl.setup.Instance$1@fc9124
31.07.2014 01:17:46 *INFO * [main] Instance: stop: stopped slingId=000, debugName=firstInstance
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 24.138 sec - in org.apache.sling.discovery.impl.cluster.ClusterTest
Running org.apache.sling.discovery.impl.cluster.ClusterLoadTest
31.07.2014 01:17:46 *INFO * [main] ClusterLoadTest: doTest(6,9): muting log output...
log4j:WARN No appenders could be found for logger (org.apache.jackrabbit.core.session.SessionState).
31.07.2014 01:18:07 *INFO * [main] ClusterLoadTest: doTest(6,9): not writing muted log output due to success...
31.07.2014 01:18:07 *INFO * [main] ClusterLoadTest: doTest(6,9): unmuted log output.
log4j:WARN No appenders could be found for logger (org.apache.jackrabbit.core.session.SessionState).
31.07.2014 01:18:07 *INFO * [main] Instance: stop: stopping slingId=ad07465a-3747-4829-b357-28dff3eaba33, debugName=firstInstance
log4j:WARN Please initialize the log4j system properly.
log4j:WARN Please initialize the log4j system properly.
31.07.2014 01:18:07 *INFO * [main] Instance: Stopping Instance [ad07465a-3747-4829-b357-28dff3eaba33]
31.07.2014 01:18:07 *INFO * [main] Instance: stop: removing listener for slingId=ad07465a-3747-4829-b357-28dff3eaba33: org.apache.sling.discovery.impl.setup.Instance$1@b9683d
31.07.2014 01:18:07 *INFO * [main] Instance: stop: stopped slingId=ad07465a-3747-4829-b357-28dff3eaba33, debugName=firstInstance
31.07.2014 01:18:07 *INFO * [main] Instance: stop: stopping slingId=a218ecfc-0d63-4f85-8330-9c06f420ea2c, debugName=subsequentInstance-1
31.07.2014 01:18:07 *INFO * [main] Instance: stop: removing listener for slingId=a218ecfc-0d63-4f85-8330-9c06f420ea2c: org.apache.sling.discovery.impl.setup.Instance$1@8fa5f5
31.07.2014 01:18:07 *INFO * [main] Instance: stop: stopped slingId=a218ecfc-0d63-4f85-8330-9c06f420ea2c, debugName=subsequentInstance-1
31.07.2014 01:18:07 *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.
31.07.2014 01:18:07 *INFO * [main] Instance: stop: stopping slingId=1746e566-3e48-45f3-98ec-39124f48abb0, debugName=subsequentInstance-2
31.07.2014 01:18:07 *INFO * [main] Instance: stop: removing listener for slingId=1746e566-3e48-45f3-98ec-39124f48abb0: org.apache.sling.discovery.impl.setup.Instance$1@1abde1e
31.07.2014 01:18:07 *INFO * [main] Instance: stop: stopped slingId=1746e566-3e48-45f3-98ec-39124f48abb0, debugName=subsequentInstance-2
31.07.2014 01:18:07 *INFO * [main] Instance: stop: stopping slingId=70156f8a-d207-4d7b-8d4a-1ed3a5b9a95c, debugName=subsequentInstance-3
31.07.2014 01:18:07 *INFO * [main] Instance: Stopping Instance [70156f8a-d207-4d7b-8d4a-1ed3a5b9a95c]
31.07.2014 01:18:07 *INFO * [main] Instance: stop: removing listener for slingId=70156f8a-d207-4d7b-8d4a-1ed3a5b9a95c: org.apache.sling.discovery.impl.setup.Instance$1@d21075
31.07.2014 01:18:07 *INFO * [main] Instance: stop: stopped slingId=70156f8a-d207-4d7b-8d4a-1ed3a5b9a95c, debugName=subsequentInstance-3
31.07.2014 01:18:07 *INFO * [main] Instance: stop: stopping slingId=61096171-948b-4326-8af9-c3dca37c1878, debugName=subsequentInstance-4
31.07.2014 01:18:07 *INFO * [main] Instance: stop: removing listener for slingId=61096171-948b-4326-8af9-c3dca37c1878: org.apache.sling.discovery.impl.setup.Instance$1@14b5b6e
31.07.2014 01:18:07 *INFO * [main] Instance: stop: stopped slingId=61096171-948b-4326-8af9-c3dca37c1878, debugName=subsequentInstance-4
31.07.2014 01:18:07 *INFO * [main] Instance: stop: stopping slingId=074ccf11-c086-4e3f-87aa-f80892542d5d, debugName=subsequentInstance-5
31.07.2014 01:18:07 *INFO * [main] Instance: stop: removing listener for slingId=074ccf11-c086-4e3f-87aa-f80892542d5d: org.apache.sling.discovery.impl.setup.Instance$1@135b33d
31.07.2014 01:18:07 *INFO * [main] Instance: stop: stopped slingId=074ccf11-c086-4e3f-87aa-f80892542d5d, debugName=subsequentInstance-5
31.07.2014 01:18:07 *INFO * [main] ClusterLoadTest: doTest(3,6): muting log output...
31.07.2014 01:18:13 *INFO * [main] ClusterLoadTest: doTest(3,6): not writing muted log output due to success...
31.07.2014 01:18:13 *INFO * [main] ClusterLoadTest: doTest(3,6): unmuted log output.
31.07.2014 01:18:13 *INFO * [main] Instance: stop: stopping slingId=87a7f1c7-4ba7-4a29-b602-51f43371a406, debugName=firstInstance
31.07.2014 01:18:13 *INFO * [main] Instance: stop: removing listener for slingId=87a7f1c7-4ba7-4a29-b602-51f43371a406: org.apache.sling.discovery.impl.setup.Instance$1@153f590
31.07.2014 01:18:13 *INFO * [main] Instance: stop: stopped slingId=87a7f1c7-4ba7-4a29-b602-51f43371a406, debugName=firstInstance
31.07.2014 01:18:13 *INFO * [main] Instance: stop: stopping slingId=39372c9a-f568-4414-ad0a-df3b2ef8eaa5, debugName=subsequentInstance-1
31.07.2014 01:18:13 *INFO * [main] Instance: stop: removing listener for slingId=39372c9a-f568-4414-ad0a-df3b2ef8eaa5: org.apache.sling.discovery.impl.setup.Instance$1@485ab4
31.07.2014 01:18:13 *INFO * [main] Instance: stop: stopped slingId=39372c9a-f568-4414-ad0a-df3b2ef8eaa5, debugName=subsequentInstance-1
31.07.2014 01:18:13 *INFO * [main] Instance: stop: stopping slingId=2dea54a7-2bc1-43eb-8864-9f6bfd6e8460, debugName=subsequentInstance-2
31.07.2014 01:18:13 *INFO * [main] Instance: Stopping Instance [2dea54a7-2bc1-43eb-8864-9f6bfd6e8460]
31.07.2014 01:18:13 *INFO * [main] Instance: stop: removing listener for slingId=2dea54a7-2bc1-43eb-8864-9f6bfd6e8460: org.apache.sling.discovery.impl.setup.Instance$1@10f892d
31.07.2014 01:18:13 *INFO * [main] Instance: stop: stopped slingId=2dea54a7-2bc1-43eb-8864-9f6bfd6e8460, debugName=subsequentInstance-2
31.07.2014 01:18:13 *INFO * [main] ClusterLoadTest: doTest(7,10): muting log output...
Killed
Results :
Tests run: 11, Failures: 0, Errors: 0, Skipped: 0
[JENKINS] Recording test results
[JENKINS] Archiving disabled
Jenkins build is back to stable : sling-trunk-1.7 » Apache Sling Resource-Based Discovery Service #724
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/sling-trunk-1.7/org.apache.sling$org.apache.sling.discovery.impl/724/>
Jenkins build is still unstable: sling-trunk-1.7 » Apache Sling Resource-Based Discovery Service #723
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/sling-trunk-1.7/org.apache.sling$org.apache.sling.discovery.impl/723/>
Jenkins build is unstable: sling-trunk-1.7 » Apache Sling Resource-Based Discovery Service #722
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/sling-trunk-1.7/org.apache.sling$org.apache.sling.discovery.impl/722/>