You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/03/09 16:18:07 UTC
[JENKINS] Lucene-Solr-4.x-Linux
(32bit/jrockit-jdk1.6.0_45-R28.2.7-4.1.0) - Build # 9624 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9624/
Java: 32bit/jrockit-jdk1.6.0_45-R28.2.7-4.1.0 -XnoOpt
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
Stack Trace:
org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
at __randomizedtesting.SeedInfo.seed([8EBC048FB6EA6EDF:8AB48B7CA44F81FE]:0)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:666)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:774)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:683)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:44)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:56)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:662)
Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
... 45 more
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:431)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:428)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:385)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:372)
at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:666)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
... 3 more
Build Log:
[...truncated 10102 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> 1130381 T3860 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
[junit4] 2> 1130381 T3860 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-OverseerTest-1394377565554
[junit4] 2> 1130382 T3860 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1130402 T3860 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment
[junit4] 2> 1130404 T3860 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1130404 T3861 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1130504 T3860 oasc.ZkTestServer.run start zk server on port:46875
[junit4] 2> 1130505 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1130570 T3867 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bf7cc33 name:ZooKeeperConnection Watcher:127.0.0.1:46875 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1130570 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1130573 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1130574 T3869 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bf81cfd name:ZooKeeperConnection Watcher:127.0.0.1:46875 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1130574 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1130575 T3860 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1130579 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1130579 T3871 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bf8580a name:ZooKeeperConnection Watcher:127.0.0.1:46875/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1130580 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1130580 T3860 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1130583 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1130584 T3873 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bf8e3a2 name:ZooKeeperConnection Watcher:127.0.0.1:46875/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1130584 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1130585 T3860 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1130588 T3860 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1130594 T3860 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:46875_solr
[junit4] 2> 1130594 T3860 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1130597 T3860 oasc.Overseer.start Overseer (id=91381928137719811-127.0.0.1:46875_solr-n_0000000000) starting
[junit4] 2> 1130600 T3860 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1130604 T3860 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1130608 T3860 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1130612 T3875 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1130613 T3860 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1130613 T3875 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1130614 T3874 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1130617 T3860 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1130619 T3860 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1130627 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1130628 T3877 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bfb5f87 name:ZooKeeperConnection Watcher:127.0.0.1:46875/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1130628 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1130630 T3860 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1130634 T3860 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 1130637 T3871 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1130637 T3877 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1130642 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1130644 T3874 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1130645 T3874 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1130645 T3874 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 1130646 T3874 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1130649 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1130651 T3877 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1130651 T3871 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1131143 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1131166 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1131180 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1131184 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1131184 T3874 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1131191 T3874 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1131191 T3874 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1131191 T3874 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1131195 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1131298 T3871 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1131299 T3877 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1131684 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1131694 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1131702 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1131703 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1131703 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1131707 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1131707 T3874 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1131713 T3874 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1131713 T3874 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1131713 T3874 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 1131717 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1131820 T3871 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1131821 T3877 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1132207 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 1132217 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 1132223 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1132224 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1132224 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1132226 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1132227 T3874 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1132232 T3874 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node4",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1132232 T3874 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1132232 T3874 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1132235 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1132337 T3877 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1132338 T3871 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1132726 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1132736 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1132736 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1132737 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1132739 T3874 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1132740 T3874 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core5",
[junit4] 2> "core_node_name":"node5",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1132740 T3874 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1132740 T3874 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1132744 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1132847 T3871 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1132847 T3877 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1133236 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1133248 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1133249 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1133249 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1133251 T3874 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1133252 T3874 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core6",
[junit4] 2> "core_node_name":"node6",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1133252 T3874 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1133252 T3874 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 1133256 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1133358 T3877 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1133358 T3871 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1133749 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 1133759 T3877 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1133762 T3860 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:46875 46875
[junit4] 2> 1134166 T3860 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1134189 T3860 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
[junit4] 2> 1134190 T3860 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1134191 T3878 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1134291 T3860 oasc.ZkTestServer.run start zk server on port:47826
[junit4] 2> 1134292 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1134293 T3884 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c295b00 name:ZooKeeperConnection Watcher:127.0.0.1:47826/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1134294 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1134295 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1134296 T3886 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c23b07d name:ZooKeeperConnection Watcher:127.0.0.1:47826 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1134296 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1134331 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1134332 T3888 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c285e16 name:ZooKeeperConnection Watcher:127.0.0.1:47826 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1134333 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1134333 T3860 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1134336 T3860 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1134338 T3860 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1134342 T3860 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1134344 T3860 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1134347 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1134348 T3890 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c3a0ec0 name:ZooKeeperConnection Watcher:127.0.0.1:47826/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1134349 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1134350 T3860 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1134353 T3860 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1134356 T3884 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1134357 T3890 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1134358 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1134359 T3892 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c3a76f4 name:ZooKeeperConnection Watcher:127.0.0.1:47826/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1134359 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1134360 T3860 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1134362 T3860 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1134368 T3860 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:47826_solr
[junit4] 2> 1134368 T3860 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1134371 T3860 oasc.Overseer.start Overseer (id=91381928385970180-127.0.0.1:47826_solr-n_0000000000) starting
[junit4] 2> 1134373 T3860 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1134378 T3860 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1134383 T3860 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1134386 T3894 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1134388 T3893 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1134389 T3894 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1134391 T3893 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1134392 T3893 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1134393 T3893 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1134393 T3893 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1134396 T3892 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1134397 T3884 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1134397 T3890 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1134889 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1134903 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1134912 T3892 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1134914 T3860 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1134915 T3893 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1134921 T3890 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1134921 T3884 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1134924 T3892 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1134925 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1134926 T3896 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c3ccf56 name:ZooKeeperConnection Watcher:127.0.0.1:47826/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1134926 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1134928 T3860 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1134933 T3860 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1134936 T3884 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1134937 T3896 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1134940 T3892 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1134940 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1134942 T3893 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1134942 T3893 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1134946 T3892 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1134952 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1134959 T3892 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1134965 T3892 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1135069 T3884 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1135069 T3896 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1135072 T3860 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1135076 T3884 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1135076 T3896 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1135079 T3860 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:47826 47826
[junit4] 2> 1135172 T3860 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1135195 T3860 oas.SolrTestCaseJ4.setUp ###Starting testStateChange
[junit4] 2> 1135197 T3860 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1135198 T3897 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1135260 T3877 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1135261 T3877 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard3/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1135262 T3877 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1135298 T3860 oasc.ZkTestServer.run start zk server on port:34849
[junit4] 2> 1135299 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1135300 T3903 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b090131 name:ZooKeeperConnection Watcher:127.0.0.1:34849/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1135301 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1135302 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1135303 T3905 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b0c33ce name:ZooKeeperConnection Watcher:127.0.0.1:34849 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1135303 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1135332 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1135332 T3907 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b384b23 name:ZooKeeperConnection Watcher:127.0.0.1:34849 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1135333 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1135333 T3860 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1135335 T3860 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1135338 T3860 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1135342 T3860 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1135344 T3860 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1135348 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1135349 T3909 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b361454 name:ZooKeeperConnection Watcher:127.0.0.1:34849/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1135349 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1135350 T3860 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1135353 T3860 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1135358 T3860 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:34849_solr
[junit4] 2> 1135359 T3860 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1135361 T3860 oasc.Overseer.start Overseer (id=91381928451964931-127.0.0.1:34849_solr-n_0000000000) starting
[junit4] 2> 1135364 T3860 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1135368 T3860 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1135372 T3860 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1135376 T3911 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1135377 T3910 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1135377 T3911 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1135379 T3860 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1135382 T3910 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1135382 T3910 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1135382 T3910 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1135385 T3909 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1135386 T3903 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1135432 T3860 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1135435 T3909 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1135437 T3910 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1135438 T3910 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"active"}
[junit4] 2> 1135438 T3910 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
[junit4] 2> 1135438 T3910 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1135441 T3909 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1135543 T3903 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1135589 T3860 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:34849 34849
[junit4] 2> 1135623 T3860 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1135645 T3860 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
[junit4] 2> 1135646 T3860 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1135647 T3912 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1135747 T3860 oasc.ZkTestServer.run start zk server on port:46342
[junit4] 2> 1135748 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1135749 T3918 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b4e76db name:ZooKeeperConnection Watcher:127.0.0.1:46342 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1135750 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1135766 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1135767 T3920 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b4ebe6d name:ZooKeeperConnection Watcher:127.0.0.1:46342 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1135767 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1135767 T3860 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1135773 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1135774 T3922 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b4f5f62 name:ZooKeeperConnection Watcher:127.0.0.1:46342/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1135774 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1135774 T3860 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1135777 T3860 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1135780 T3860 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1135782 T3860 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1135785 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1135786 T3924 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b5a3e49 name:ZooKeeperConnection Watcher:127.0.0.1:46342/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1135787 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1135788 T3860 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1135791 T3860 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1135797 T3922 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1135797 T3924 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1135798 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1135798 T3926 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b5f6325 name:ZooKeeperConnection Watcher:127.0.0.1:46342/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1135799 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1135800 T3860 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1135802 T3860 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1135807 T3860 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:46342_solr
[junit4] 2> 1135807 T3860 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1135810 T3860 oasc.Overseer.start Overseer (id=91381928481325060-127.0.0.1:46342_solr-n_0000000000) starting
[junit4] 2> 1135812 T3860 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1135816 T3860 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1135821 T3860 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1135824 T3928 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1135825 T3928 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1135825 T3927 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1136829 T3926 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1136834 T3927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1136835 T3927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1136836 T3927 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1136836 T3927 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1136842 T3926 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1136844 T3922 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1136845 T3924 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1137330 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1137354 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1137380 T3926 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1137382 T3860 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1137386 T3927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1137392 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1137392 T3926 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1137398 T3927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1137399 T3927 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1137405 T3926 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1137512 T3924 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1137512 T3922 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1138570 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1138579 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1138580 T3930 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b814516 name:ZooKeeperConnection Watcher:127.0.0.1:46342/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1138581 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1138585 T3860 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:46342_solr
[junit4] 2> 1138585 T3860 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1138587 T3860 oasc.Overseer.start Overseer (id=91381928481325061-127.0.0.1:46342_solr-n_0000000001) starting
[junit4] 2> 1138593 T3932 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1138594 T3932 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1138595 T3931 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1138599 T3931 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1138600 T3931 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1138600 T3931 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1138608 T3930 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1138609 T3924 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1138610 T3922 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1138666 T3930 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1138666 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1138669 T3931 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1138678 T3860 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91381928481325059-node1_core1-n_0000000002
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:276)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:273)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:273)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
[junit4] 2> at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
[junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:666)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:597)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4] 2> at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 1138678 T3924 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1138682 T3931 oasc.SolrException.log ERROR Problem cleaning up collection in zk:collection1:org.apache.zookeeper.KeeperException$NotEmptyException: KeeperErrorCode = Directory not empty for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:125)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:176)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:173)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:173)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:635)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:630)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:630)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:630)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:976)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:253)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:202)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 1138683 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1138687 T3930 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1138691 T3930 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1138693 T3931 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 1138693 T3924 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1138696 T3930 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1138700 T3930 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1138702 T3931 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 1138705 T3930 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1138807 T3924 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1138807 T3922 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1139690 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1140694 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1141698 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1142702 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1143710 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1144714 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1145718 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1146722 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1147727 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1148736 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1149741 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1150746 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1151752 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1152756 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1153764 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1153770 T3922 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1153770 T3924 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1153773 T3860 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:46342 46342
[junit4] 2> 1153952 T3860 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=8EBC048FB6EA6EDF -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=hu_HU -Dtests.timezone=America/Los_Angeles -Dtests.file.encoding=UTF-8
[junit4] ERROR 18.3s J0 | OverseerTest.testOverseerFailure <<<
[junit4] > Throwable #1: org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
[junit4] > at __randomizedtesting.SeedInfo.seed([8EBC048FB6EA6EDF:8AB48B7CA44F81FE]:0)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
[junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
[junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
[junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
[junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:666)
[junit4] > at java.lang.Thread.run(Thread.java:662)
[junit4] > Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
[junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
[junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
[junit4] > ... 45 more
[junit4] > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:431)
[junit4] > at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:428)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:385)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:372)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
[junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
[junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
[junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
[junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
[junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:666)
[junit4] > ... 3 more
[junit4] 2> 1153988 T3860 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
[junit4] 2> 1153990 T3860 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1153990 T3933 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1154090 T3860 oasc.ZkTestServer.run start zk server on port:37487
[junit4] 2> 1154092 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1154094 T3939 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b4d3e04 name:ZooKeeperConnection Watcher:127.0.0.1:37487 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1154094 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1154119 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1154121 T3941 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b4e3ec4 name:ZooKeeperConnection Watcher:127.0.0.1:37487 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1154121 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1154121 T3860 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1154125 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1154126 T3943 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b49d923 name:ZooKeeperConnection Watcher:127.0.0.1:37487/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1154126 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1154126 T3860 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1154129 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1154130 T3945 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b4be28e name:ZooKeeperConnection Watcher:127.0.0.1:37487/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1154130 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1154131 T3860 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1154134 T3860 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1154139 T3860 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:37487_solr
[junit4] 2> 1154139 T3860 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1154142 T3860 oasc.Overseer.start Overseer (id=91381929683582979-127.0.0.1:37487_solr-n_0000000000) starting
[junit4] 2> 1154144 T3860 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1154148 T3860 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1154153 T3860 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1154156 T3947 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1154159 T3860 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1154160 T3947 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1154161 T3946 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1154163 T3860 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1154166 T3860 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1154169 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1154171 T3949 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b826ba6 name:ZooKeeperConnection Watcher:127.0.0.1:37487/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1154171 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1154173 T3860 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1154177 T3860 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 1154180 T3943 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1154180 T3949 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1154182 T3945 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1154184 T3946 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1154185 T3946 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1154185 T3946 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 1154186 T3946 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1154188 T3945 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1154190 T3943 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1154191 T3949 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1154683 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1154703 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1154720 T3945 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1154723 T3946 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1154725 T3945 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1154730 T3946 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1154730 T3946 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1154731 T3946 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1154734 T3945 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1154838 T3943 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1154839 T3949 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1155225 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1155240 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1155250 T3945 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1155250 T3945 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1155251 T3945 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1155254 T3945 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1155255 T3946 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1155265 T3946 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1155266 T3946 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1155266 T3946 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 1155271 T3945 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1155375 T3943 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1155375 T3949 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1155755 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 1155766 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 1155772 T3945 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1155772 T3945 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1155772 T3945 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1155774 T3946 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1155777 T3945 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1155881 T3949 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1155882 T3943 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1155925 T3945 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1155925 T3945 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1155925 T3945 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1155928 T3945 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1155928 T3946 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1155929 T3946 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core0",
[junit4] 2> "core_node_name":"node0",
[
[...truncated too long message...]
o ZooKeeper
[junit4] 2> 1214575 T4341 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c02b639 name:ZooKeeperConnection Watcher:127.0.0.1:41637 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1214576 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1214577 T3860 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1214583 T3860 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1214589 T3860 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1214596 T3860 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1214601 T3860 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1214609 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1214611 T4343 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c1abb68 name:ZooKeeperConnection Watcher:127.0.0.1:41637/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1214611 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1214614 T3860 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1214621 T3860 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1214627 T4343 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1214627 T4337 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1214629 T3860 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1214631 T4345 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1be4a379 name:ZooKeeperConnection Watcher:127.0.0.1:41637/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1214631 T3860 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1214633 T3860 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1214639 T3860 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1214649 T3860 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:41637_solr
[junit4] 2> 1214650 T3860 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1214656 T3860 oasc.Overseer.start Overseer (id=91381933644644356-127.0.0.1:41637_solr-n_0000000000) starting
[junit4] 2> 1214660 T3860 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1214669 T3860 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1214680 T3860 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1214686 T4347 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1214688 T4347 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1214689 T4346 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1214711 T4346 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1214713 T4346 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=12 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"12",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1214713 T4346 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
[junit4] 2> 1214714 T4346 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1214719 T4345 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1214721 T4343 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1214721 T4337 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1215191 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1215214 T3860 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1215229 T4345 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1215231 T3860 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1215235 T4346 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1215239 T4337 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1215240 T4343 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1215243 T3860 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:41637 41637
[junit4] 2> 1215443 T3860 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1215448 T3860 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 1215448 T3860 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1218449 T3860 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Asserting, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=hu_HU, timezone=America/Los_Angeles
[junit4] 2> NOTE: Linux 3.8.0-36-generic i386/Oracle Corporation 1.6.0_45 (32-bit)/cpus=8,threads=1,free=253052272,total=449683456
[junit4] 2> NOTE: All tests run in this JVM: [DistributedSuggestComponentTest, TestCharFilters, TestJmxMonitoredMap, DirectUpdateHandlerOptimizeTest, BasicDistributedZkTest, SolrXmlInZkTest, ScriptEngineTest, TestDocumentBuilder, TestSolrQueryParser, LoggingHandlerTest, CoreAdminHandlerTest, TestSolrXmlPersistence, TestBM25SimilarityFactory, BadComponentTest, RecoveryZkTest, RemoteQueryErrorTest, CursorMarkTest, ShardRoutingTest, JsonLoaderTest, ResponseLogComponentTest, TestOverriddenPrefixQueryForCustomFieldType, IndexSchemaTest, TestNoOpRegenerator, TestManagedSchema, TestCustomSort, SuggestComponentTest, DocValuesTest, BasicFunctionalityTest, ResourceLoaderTest, TermVectorComponentTest, LeaderElectionTest, HdfsDirectoryTest, ExternalFileFieldSortTest, FileBasedSpellCheckerTest, DistributedTermsComponentTest, TestReversedWildcardFilterFactory, ParsingFieldUpdateProcessorsTest, TestLuceneMatchVersion, SuggesterFSTTest, CircularListTest, MoreLikeThisHandlerTest, SliceStateUpdateTest, FieldMutatingUpdateProcessorTest, TestUniqueKeyFieldResource, TestSort, TestNRTOpen, TestLMJelinekMercerSimilarityFactory, SearchHandlerTest, TestDynamicFieldCollectionResource, ClusterStateTest, CSVRequestHandlerTest, PrimitiveFieldTypeTest, TestMergePolicyConfig, ShardSplitTest, AnalysisAfterCoreReloadTest, TestSolrIndexConfig, TestCloudManagedSchemaAddField, AddBlockUpdateTest, QueryElevationComponentTest, DOMUtilTest, BJQParserTest, TestWriterPerf, TestLRUCache, TestHighFrequencyDictionaryFactory, TestSolrXmlPersistor, DeleteReplicaTest, DateMathParserTest, SuggesterTest, TestConfig, QueryParsingTest, TestJoin, LegacyHTMLStripCharFilterTest, AnalysisErrorHandlingTest, ZkCLITest, HdfsSyncSliceTest, TestQueryUtils, SpellPossibilityIteratorTest, SolrIndexSplitterTest, TestSolrDeletionPolicy1, DistributedQueryElevationComponentTest, SoftAutoCommitTest, UUIDFieldTest, TestReplicationHandler, SimpleFacetsTest, TestFaceting, SchemaVersionSpecificBehaviorTest, TestSearchPerf, TestElisionMultitermQuery, ReturnFieldsTest, StatelessScriptUpdateProcessorFactoryTest, MigrateRouteKeyTest, CoreMergeIndexesAdminHandlerTest, SyncSliceTest, OpenCloseCoreStressTest, OverseerTest]
[junit4] Completed on J0 in 88.14s, 9 tests, 1 error <<< FAILURES!
[...truncated 554 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:471: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:451: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:490: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1278: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:911: There were test failures: 369 suites, 1578 tests, 1 error, 37 ignored (8 assumptions)
Total time: 77 minutes 41 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jrockit-jdk1.6.0_45-R28.2.7-4.1.0 -XnoOpt
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.6.0_45) - Build # 9625
- Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9625/
Java: 32bit/jdk1.6.0_45 -client -XX:+UseSerialGC
All tests passed
Build Log:
[...truncated 618 lines...]
[junit4] JVM J1: stdout was not empty, see: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/build/core/test/temp/junit4-J1-20140309_162051_736.sysout
[junit4] >>> JVM J1: stdout (verbatim) ----
[junit4] #
[junit4] # A fatal error has been detected by the Java Runtime Environment:
[junit4] #
[junit4] # SIGSEGV (0xb) at pc=0xf55558b3, pid=12029, tid=4085967680
[junit4] #
[junit4] # JRE version: 6.0_45-b06
[junit4] # Java VM: Java HotSpot(TM) Client VM (20.45-b01 mixed mode, sharing linux-x86 )
[junit4] # Problematic frame:
[junit4] # J org.apache.lucene.store.TestDirectory.testDirectInstantiation()V
[junit4] #
[junit4] # An error report file with more information is saved as:
[junit4] # /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/build/core/test/J1/hs_err_pid12029.log
[junit4] #
[junit4] # If you would like to submit a bug report, please visit:
[junit4] # http://java.sun.com/webapps/bugreport/crash.jsp
[junit4] #
[junit4] <<< JVM J1: EOF ----
[...truncated 779 lines...]
[junit4] ERROR: JVM J1 ended with an exception, command line: /var/lib/jenkins/tools/java/32bit/jdk1.6.0_45/jre/bin/java -client -XX:+UseSerialGC -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/heapdumps -Dtests.prefix=tests -Dtests.seed=FAE04F5E0D90F1BC -Xmx512M -Dtests.iters= -Dtests.verbose=false -Dtests.infostream=false -Dtests.codec=random -Dtests.postingsformat=random -Dtests.docvaluesformat=random -Dtests.locale=random -Dtests.timezone=random -Dtests.directory=random -Dtests.linedocsfile=europarl.lines.txt.gz -Dtests.luceneMatchVersion=4.8 -Dtests.cleanthreads=perMethod -Djava.util.logging.config.file=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/tools/junit4/logging.properties -Dtests.nightly=false -Dtests.weekly=false -Dtests.slow=true -Dtests.asserts.gracious=false -Dtests.multiplier=3 -DtempDir=. -Djava.io.tmpdir=. -Djunit4.tempDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/build/core/test/temp -Dclover.db.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/build/clover/db -Djava.security.manager=org.apache.lucene.util.TestSecurityManager -Djava.security.policy=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/tools/junit4/tests.policy -Dlucene.version=4.8-SNAPSHOT -Djetty.testMode=1 -Djetty.insecurerandom=1 -Dsolr.directoryFactory=org.apache.solr.core.MockDirectoryFactory -Djava.awt.headless=true -Djdk.map.althashing.threshold=0 -Dtests.disableHdfs=true -Dfile.encoding=ISO-8859-1 -classpath /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/build/test-framework/classes/java:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/build/codecs/classes/java:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/test-framework/lib/junit-4.10.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/test-framework/lib/randomizedtesting-runner-2.0.13.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/build/core/classes/java:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/build/core/classes/test:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-launcher.jar:/var/lib/jenkins/.ant/lib/ivy-2.3.0.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jai.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-swing.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-oro.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jmf.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-xalan2.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-javamail.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-resolver.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-testutil.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-commons-logging.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-log4j.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-junit.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jsch.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-commons-net.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-bsf.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jdepend.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-netrexx.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-regexp.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-junit4.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-bcel.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-antlr.jar:/var/lib/jenkins/tools/java/32bit/jdk1.6.0_45/lib/tools.jar:/var/lib/jenkins/.ivy2/cache/com.carrotsearch.randomizedtesting/junit4-ant/jars/junit4-ant-2.0.13.jar -ea:org.apache.lucene... -ea:org.apache.solr... com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe -eventsfile /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/build/core/test/temp/junit4-J1-20140309_162051_736.events @/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/build/core/test/temp/junit4-J1-20140309_162051_736.suites
[junit4] ERROR: JVM J1 ended with an exception: Forked process returned with error code: 134. Very likely a JVM crash. Process output piped in logs above.
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4.executeSlave(JUnit4.java:1373)
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4.access$000(JUnit4.java:119)
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:911)
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:908)
[junit4] at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
[junit4] at java.util.concurrent.FutureTask.run(FutureTask.java:138)
[junit4] at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
[junit4] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
[junit4] at java.lang.Thread.run(Thread.java:662)
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:471: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:451: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/build.xml:49: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1278: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:911: At least one slave process threw an exception, first: Forked process returned with error code: 134. Very likely a JVM crash. Process output piped in logs above.
Total time: 25 minutes 14 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.6.0_45 -client -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure