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/24 14:38:56 UTC
[JENKINS] Lucene-Solr-4.x-Windows (64bit/jdk1.7.0_60-ea-b10) -
Build # 3811 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/3811/
Java: 64bit/jdk1.7.0_60-ea-b10 -XX:+UseCompressedOops -XX:+UseSerialGC
3 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([8E986FDB0F0B3AE0:8A90E0281DAED5C1]: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.checkIfIamLeader(LeaderElector.java:156)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:156)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:667)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1617)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
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:359)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
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)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at java.lang.Thread.run(Thread.java:744)
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)
... 46 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)
... 47 more
FAILED: org.apache.solr.core.TestConfigSets.testConfigSetServiceFindsConfigSets
Error Message:
Expected: is "C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\findsConfigSets\/core1/data/" got: "C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\findsConfigSets\/core1\data\"
Stack Trace:
java.lang.AssertionError:
Expected: is "C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\findsConfigSets\/core1/data/"
got: "C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\findsConfigSets\/core1\data\"
at __randomizedtesting.SeedInfo.seed([8E986FDB0F0B3AE0:539632139B801C92]:0)
at org.junit.Assert.assertThat(Assert.java:780)
at org.junit.Assert.assertThat(Assert.java:738)
at org.apache.solr.core.TestConfigSets.testConfigSetServiceFindsConfigSets(TestConfigSets.java:66)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1617)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
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:359)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
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)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at java.lang.Thread.run(Thread.java:744)
FAILED: junit.framework.TestSuite.org.apache.solr.core.TestConfigSets
Error Message:
ERROR: SolrIndexSearcher opens=4 closes=3
Stack Trace:
java.lang.AssertionError: ERROR: SolrIndexSearcher opens=4 closes=3
at __randomizedtesting.SeedInfo.seed([8E986FDB0F0B3AE0]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.SolrTestCaseJ4.endTrackingSearchers(SolrTestCaseJ4.java:412)
at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:176)
at sun.reflect.GeneratedMethodAccessor28.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1617)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:789)
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)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at java.lang.Thread.run(Thread.java:744)
Build Log:
[...truncated 10577 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> 788789 T1998 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
[junit4] 2> 788789 T1998 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-OverseerTest-1395665745516
[junit4] 2> 788790 T1998 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 788795 T1998 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
[junit4] 2> 788795 T1998 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 788795 T1999 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 788873 T1998 oasc.ZkTestServer.run start zk server on port:60158
[junit4] 2> 788875 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 788881 T2005 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2316b52a name:ZooKeeperConnection Watcher:127.0.0.1:60158/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 788881 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 788882 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 788884 T2007 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e5d3855 name:ZooKeeperConnection Watcher:127.0.0.1:60158 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 788885 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 788888 T2000 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144f42936780001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 788894 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 788897 T2009 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4cc0d865 name:ZooKeeperConnection Watcher:127.0.0.1:60158 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 788898 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 788898 T1998 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 788903 T1998 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 788909 T1998 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 788913 T1998 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 788916 T1998 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 788924 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 788927 T2011 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2065a025 name:ZooKeeperConnection Watcher:127.0.0.1:60158/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 788928 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 788930 T1998 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 788934 T1998 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 788938 T2011 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 788940 T2005 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 788941 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 788943 T2013 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7732e562 name:ZooKeeperConnection Watcher:127.0.0.1:60158/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 788943 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 788945 T1998 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 788949 T1998 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 788955 T1998 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:60158_solr
[junit4] 2> 788956 T1998 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 788960 T1998 oasc.Overseer.start Overseer (id=91466350298923012-127.0.0.1:60158_solr-n_0000000000) starting
[junit4] 2> 788964 T1998 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 788970 T1998 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 788976 T1998 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 788981 T1998 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 788987 T1998 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 788995 T1998 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 789005 T2015 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 789007 T2015 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 789007 T2014 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 789011 T2014 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 789012 T2014 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> 789013 T2014 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 789013 T2014 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 789017 T2013 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 789019 T2005 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> 789019 T2011 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> 789396 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 789412 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 789421 T2013 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 789422 T1998 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 789423 T2014 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 789425 T2005 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 789426 T2011 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 789428 T2000 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144f42936780003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 789430 T2013 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 789431 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 789433 T2017 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e334383 name:ZooKeeperConnection Watcher:127.0.0.1:60158/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 789434 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 789435 T1998 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 789438 T1998 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 789442 T2005 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 789443 T2017 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 789446 T2013 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 789446 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 789447 T2014 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> 789447 T2014 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 789452 T2013 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 789458 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 789465 T2013 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 789471 T2013 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 789551 T2017 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> 789551 T2005 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> 789553 T1998 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 789558 T2000 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144f42936780004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 789560 T2005 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 789560 T2017 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 789562 T2000 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144f42936780005, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 789564 T2000 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144f42936780000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 789566 T1998 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:60158 60158
[junit4] 2> 790777 T2014 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue-work/qn-0000000002
[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.getData(ZooKeeper.java:1155)
[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.DistributedQueue.remove(DistributedQueue.java:178)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.poll(DistributedQueue.java:493)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:265)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 791431 T1998 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 791438 T1998 oas.SolrTestCaseJ4.setUp ###Starting testPlaceholders
[junit4] 2> 791438 T1998 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 791439 T2018 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 791525 T1998 oasc.ZkTestServer.run start zk server on port:60179
[junit4] 2> 791526 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 791531 T2024 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4f00f9cc name:ZooKeeperConnection Watcher:127.0.0.1:60179/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 791532 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 791534 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 791537 T2026 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1eb9c31a name:ZooKeeperConnection Watcher:127.0.0.1:60179 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 791537 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 791604 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 791610 T2028 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@41ed6a91 name:ZooKeeperConnection Watcher:127.0.0.1:60179 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 791610 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 791610 T1998 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 791620 T1998 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 791630 T1998 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 791635 T1998 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 791640 T1998 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 791647 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 791651 T2030 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e8ee2b8 name:ZooKeeperConnection Watcher:127.0.0.1:60179/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 791651 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 791654 T1998 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 791659 T1998 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 791664 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 791676 T2030 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 791678 T2024 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 791679 T2032 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3cc60293 name:ZooKeeperConnection Watcher:127.0.0.1:60179/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 791679 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 791681 T1998 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 791684 T1998 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 791693 T1998 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:60179_solr
[junit4] 2> 791693 T1998 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 791700 T1998 oasc.Overseer.start Overseer (id=91466350472200196-127.0.0.1:60179_solr-n_0000000000) starting
[junit4] 2> 791704 T1998 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 791712 T1998 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 791719 T1998 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 791726 T1998 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 791733 T1998 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 791742 T1998 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 791754 T2034 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 791756 T2034 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 791758 T2033 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 791764 T2033 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 791765 T2033 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> 791765 T2033 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
[junit4] 2> 791765 T2033 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard12
[junit4] 2> 791771 T2032 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 791772 T2030 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> 791772 T2024 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> 792184 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard12/election
[junit4] 2> 792200 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard12
[junit4] 2> 792217 T2032 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 792219 T1998 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 792219 T2033 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 792224 T2019 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144f42940cc0004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 792226 T2030 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 792227 T2024 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 792233 T2019 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144f42940cc0000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 792235 T1998 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:60179 60179
[junit4] 2> 793498 T2033 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue-work/qn-
[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.create(ZooKeeper.java:783)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:242)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:239)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:239)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.createData(DistributedQueue.java:311)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.offer(DistributedQueue.java:295)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:252)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 794155 T1998 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 794160 T1998 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
[junit4] 2> 794160 T1998 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 794161 T2035 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 794247 T1998 oasc.ZkTestServer.run start zk server on port:60197
[junit4] 2> 794249 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 794254 T2041 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@66fca4f name:ZooKeeperConnection Watcher:127.0.0.1:60197 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 794254 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 794293 T2036 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144f4294b710000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 794295 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 794297 T2043 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f23ea9f name:ZooKeeperConnection Watcher:127.0.0.1:60197 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 794298 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 794298 T1998 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 794303 T2036 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144f4294b710001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 794303 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 794307 T2045 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a0de7f7 name:ZooKeeperConnection Watcher:127.0.0.1:60197/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 794307 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 794307 T1998 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 794311 T1998 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 794315 T1998 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 794317 T1998 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 794322 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 794325 T2047 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ed1accb name:ZooKeeperConnection Watcher:127.0.0.1:60197/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 794326 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 794327 T1998 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 794331 T1998 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 794336 T2047 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 794336 T2045 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 794337 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 794341 T2049 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26a0f777 name:ZooKeeperConnection Watcher:127.0.0.1:60197/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 794341 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 794342 T1998 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 794347 T1998 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 794354 T1998 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:60197_solr
[junit4] 2> 794355 T1998 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 794359 T1998 oasc.Overseer.start Overseer (id=91466350650785796-127.0.0.1:60197_solr-n_0000000000) starting
[junit4] 2> 794363 T1998 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 794369 T1998 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 794375 T1998 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 794381 T1998 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 794386 T1998 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 794393 T1998 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 794403 T2051 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 794405 T2051 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 794405 T2050 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 795257 T2049 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 795260 T2050 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 795261 T2050 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> 795261 T2050 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 795261 T2050 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 795266 T2049 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 795266 T2045 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> 795266 T2047 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> 795683 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 795699 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 795709 T2049 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 795710 T1998 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 795711 T2050 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 795715 T2049 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 795715 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 795718 T2050 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> 795718 T2050 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 795723 T2049 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 795813 T2047 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> 795813 T2045 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> 795818 T2036 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144f4294b710004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 796671 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 796684 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 796688 T2053 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@38ca6dad name:ZooKeeperConnection Watcher:127.0.0.1:60197/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 796688 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 796696 T1998 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:60197_solr
[junit4] 2> 796696 T1998 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 796700 T1998 oasc.Overseer.start Overseer (id=91466350650785797-127.0.0.1:60197_solr-n_0000000001) starting
[junit4] 2> 796721 T2055 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 796722 T2055 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 796725 T2054 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 796725 T2054 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 796728 T2047 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> 796728 T2045 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> 796734 T2054 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> 796734 T2054 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 796736 T2047 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> 796737 T2045 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> 796740 T2054 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 796745 T2054 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 796745 T2054 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> 796745 T2054 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 796751 T2053 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 796753 T2047 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> 796753 T2045 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> 796777 T2053 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 796777 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 796779 T2054 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 796789 T1998 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91466350650785795-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:1155)
[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:156)
[junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:667)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1617)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
[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:359)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
[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:359)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 796793 T1998 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91466350650785795-node1_core1-n_0000000001
[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:1155)
[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.checkIfIamLeader(LeaderElector.java:156)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
[junit4] 2> at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:156)
[junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:667)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1617)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
[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:359)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
[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:359)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 796794 T2047 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 796796 T2054 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:1017)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:294)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:239)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 796798 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 796799 T2053 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 796806 T2053 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 796807 T2054 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 796809 T2047 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 796813 T2053 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 796817 T2053 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 796819 T2054 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 796823 T2053 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 796912 T2045 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> 796913 T2047 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> 797656 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 798516 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 799446 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 800393 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 801334 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 802280 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 803224 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 804166 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 805113 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 806059 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 807002 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 807942 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 808979 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 810021 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 811060 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 811067 T2047 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 811068 T2045 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 811074 T2036 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144f4294b710002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 811075 T1998 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:60197 60197
[junit4] 2> 813397 T1998 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=8E986FDB0F0B3AE0 -Dtests.slow=true -Dtests.locale=es_DO -Dtests.timezone=Atlantic/Bermuda -Dtests.file.encoding=US-ASCII
[junit4] ERROR 19.3s | 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([8E986FDB0F0B3AE0:8A90E0281DAED5C1]: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.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:156)
[junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:667)
[junit4] > at java.lang.Thread.run(Thread.java:744)
[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] > ... 46 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] > ... 47 more
[junit4] 2> 813414 T1998 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
[junit4] 2> 813414 T1998 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 813416 T2056 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 813520 T1998 oasc.ZkTestServer.run start zk server on port:60218
[junit4] 2> 813522 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 813536 T2062 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b3e3951 name:ZooKeeperConnection Watcher:127.0.0.1:60218 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 813537 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 813596 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 813600 T2064 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@66b77558 name:ZooKeeperConnection Watcher:127.0.0.1:60218 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 813600 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 813601 T1998 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 813608 T2057 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144f42996ab0001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 813610 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 813612 T2066 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3765d912 name:ZooKeeperConnection Watcher:127.0.0.1:60218/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 813612 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 813612 T1998 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 813617 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 813619 T2068 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@292f93ae name:ZooKeeperConnection Watcher:127.0.0.1:60218/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 813619 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 813620 T1998 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 813624 T1998 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 813631 T1998 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:60218_solr
[junit4] 2> 813631 T1998 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 813635 T1998 oasc.Overseer.start Overseer (id=91466351912878083-127.0.0.1:60218_solr-n_0000000000) starting
[junit4] 2> 813638 T1998 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 813644 T1998 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 813651 T1998 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 813657 T1998 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 813665 T1998 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 813671 T1998 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 813681 T2070 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 813682 T1998 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 813682 T2070 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 813683 T2069 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 813686 T1998 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 813689 T1998 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 813694 T1998 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 813697 T2072 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@27c534e name:ZooKeeperConnection Watcher:127.0.0.1:60218/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 813697 T1998 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 813700 T1998 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 813709 T1998 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 813716 T2066 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 813717 T2072 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 813723 T2068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 813728 T2069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 813730 T2069 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> 813730 T2069 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 813730 T2069 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 813736 T2068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 813738 T2066 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> 813738 T2072 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> 814238 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 814258 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 814272 T2068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 814276 T2068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 814277 T2069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 814285 T2069 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> 814285 T2069 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 814285 T2069 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 814290 T2068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 814397 T2072 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> 814397 T2066 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> 814791 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 814807 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 814816 T2068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 814816 T2068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 814817 T2068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 814821 T2068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 814822 T2069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 814829 T2069 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> 814829 T2069 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 814829 T2069 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 814834 T2068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 814942 T2072 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> 814943 T2066 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> 815335 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 815350 T1998 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 815359 T2068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 815359 T2068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 815360 T2068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 815362 T2069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 815368 T2068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 815475 T2066 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> 815476 T2072 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> 815522 T2068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 815522 T2068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 815522 T2068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 815529 T2069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 815532 T2069 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",
[junit4] 2> "collection":"",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 815534 T2068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 815543 T2069 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
[junit4] 2> "operation":"deletecore",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core0",
[junit4] 2> "core_node_name":"node0",
[junit4] 2> "collection":""}
[junit4] 2> 815548 T2068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 815550 T2069 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":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 815550 T2069 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3]
[junit4] 2> 815550 T2069 oasc.Overseer$ClusterStateUpdater.updateState A
[...truncated too long message...]
DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 1514308 T5034 oass.SolrIndexSearcher.<init> Opening Searcher@7e0f3471[core1] main
[junit4] 2> 1514308 T5034 oasc.CoreContainer.registerCore replacing core: core1
[junit4] 2> 1514308 T5034 oasc.SolrCore.close [core1] CLOSING SolrCore org.apache.solr.core.SolrCore@183c275f
[junit4] 2> 1514308 T5034 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 1514310 T5041 oasc.SolrCore.registerSearcher [core1] Registered new searcher Searcher@7e0f3471[core1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1514310 T5034 oasc.SolrCore.closeSearcher [core1] Closing main searcher on request.
[junit4] 2> 1514310 T5034 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=2096468655
[junit4] 2> 1514310 T5034 oasc.SolrCore.close [core1] CLOSING SolrCore org.apache.solr.core.SolrCore@153cda67
[junit4] 2> 1514310 T5034 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 1514310 T5034 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 1514310 T5034 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 1514310 T5034 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 1514317 T5034 oasc.SolrCore.closeSearcher [core1] Closing main searcher on request.
[junit4] 2> 1514317 T5034 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1514317 T5034 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\core-reload\.\core-reload/core\data\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\core-reload\.\core-reload/core\data\;done=false>>]
[junit4] 2> 1514317 T5034 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\core-reload\.\core-reload/core\data\
[junit4] 2> 1514317 T5034 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\core-reload\.\core-reload/core\data\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\core-reload\.\core-reload/core\data\index;done=false>>]
[junit4] 2> 1514317 T5034 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\core-reload\.\core-reload/core\data\index
[junit4] 2> 1514317 T5034 oas.SolrTestCaseJ4.tearDown ###Ending testConfigSetOnCoreReload
[junit4] 2> 1514321 T5034 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 1650185 T5034 oas.SolrTestCaseJ4.endTrackingSearchers ERROR ERROR: SolrIndexSearcher opens=4 closes=3
[junit4] 2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=DefaultSimilarity, locale=sr_RS_#Latn, timezone=America/Indiana/Vevay
[junit4] 2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.7.0_60-ea (64-bit)/cpus=2,threads=1,free=143725584,total=259837952
[junit4] 2> NOTE: All tests run in this JVM: [TestMultiCoreConfBootstrap, DistributedTermsComponentTest, SearchHandlerTest, HighlighterConfigTest, ShardRoutingCustomTest, TermsComponentTest, TestConfig, ShowFileRequestHandlerTest, CachingDirectoryFactoryTest, TestTrie, TestFoldingMultitermQuery, AlternateDirectoryTest, TestStressRecovery, ExternalFileFieldSortTest, TestCSVLoader, BasicDistributedZk2Test, LukeRequestHandlerTest, TestDocumentBuilder, TestSolr4Spatial, TestRecovery, TestArbitraryIndexDir, OpenCloseCoreStressTest, TestCustomSort, TestSolrJ, TestSolrDeletionPolicy1, TestValueSourceCache, RecoveryZkTest, BasicFunctionalityTest, OutputWriterTest, ScriptEngineTest, TestStressUserVersions, TestSolrXMLSerializer, BasicZkTest, TestHighlightDedupGrouping, CSVRequestHandlerTest, PrimitiveFieldTypeTest, SolrRequestParserTest, CursorMarkTest, MBeansHandlerTest, CustomCollectionTest, TestBlendedInfixSuggestions, DocValuesTest, TestSurroundQueryParser, OverseerStatusTest, TestSchemaSimilarityResource, URLClassifyProcessorTest, TestOverriddenPrefixQueryForCustomFieldType, XmlUpdateRequestHandlerTest, CoreAdminCreateDiscoverTest, TestSolrQueryParserResource, TestUpdate, TestCoreContainer, FileUtilsTest, TestImplicitCoreProperties, TestFuzzyAnalyzedSuggestions, TestStressVersions, AddBlockUpdateTest, TestHighFrequencyDictionaryFactory, SampleTest, SolrPluginUtilsTest, TestPostingsSolrHighlighter, TestRangeQuery, DateMathParserTest, DirectSolrSpellCheckerTest, HdfsChaosMonkeySafeLeaderTest, TestStressReorder, TestSolrQueryParser, DebugComponentTest, TestIBSimilarityFactory, TestCoreDiscovery, TestPerFieldSimilarity, QueryResultKeyTest, TestDynamicFieldResource, SolrCoreTest, OverseerRolesTest, TestNoOpRegenerator, TestAtomicUpdateErrorCases, SuggesterTSTTest, SolrCoreCheckLockOnStartupTest, DirectUpdateHandlerTest, TestRealTimeGet, RequestHandlersTest, OverseerTest, TestJoin, TestDistributedMissingSort, TestReload, TermVectorComponentTest, CoreContainerCoreInitFailuresTest, HdfsBasicDistributedZk2Test, SimpleFacetsTest, SuggesterWFSTTest, HdfsUnloadDistributedZkTest, IndexBasedSpellCheckerTest, TestSolrXmlPersistor, DocumentAnalysisRequestHandlerTest, DistributedSuggestComponentTest, MultiTermTest, TestCollationKeyRangeQueries, CircularListTest, TestJmxIntegration, AnalysisErrorHandlingTest, JsonLoaderTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestRecoveryHdfs, DistributedExpandComponentTest, PathHierarchyTokenizerFactoryTest, PolyFieldTest, TestSearcherReuse, ConvertedLegacyTest, TestJmxMonitoredMap, TestLFUCache, HighlighterTest, HardAutoCommitTest, TestBinaryResponseWriter, BadCopyFieldTest, RegexBoostProcessorTest, SolrCmdDistributorTest, TestLMJelinekMercerSimilarityFactory, SpatialFilterTest, TestStressLucene, TestQuerySenderNoQuery, TestSolrDeletionPolicy2, DefaultValueUpdateProcessorTest, ZkNodePropsTest, TestPartialUpdateDeduplication, FieldMutatingUpdateProcessorTest, TestOmitPositions, AssignTest, TestBadConfig, OpenExchangeRatesOrgProviderTest, TestFaceting, DirectSolrConnectionTest, TestFileDictionaryLookup, ZkControllerTest, FullSolrCloudDistribCmdsTest, TestSuggestSpellingConverter, FileBasedSpellCheckerTest, PreAnalyzedUpdateProcessorTest, MinimalSchemaTest, SuggesterFSTTest, JSONWriterTest, AliasIntegrationTest, TestCloudManagedSchemaAddField, TestDefaultSimilarityFactory, StatsComponentTest, UniqFieldsUpdateProcessorFactoryTest, QueryEqualityTest, FastVectorHighlighterTest, UnloadDistributedZkTest, AsyncMigrateRouteKeyTest, TestBM25SimilarityFactory, DeleteReplicaTest, IndexSchemaTest, TestZkChroot, BJQParserTest, TestLMDirichletSimilarityFactory, TestFunctionQuery, InfoHandlerTest, FieldAnalysisRequestHandlerTest, TriLevelCompositeIdRoutingTest, PrimUtilsTest, TestSolrIndexConfig, DocValuesMissingTest, TestSerializedLuceneMatchVersion, BadIndexSchemaTest, TestConfigSets]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestConfigSets -Dtests.seed=8E986FDB0F0B3AE0 -Dtests.slow=true -Dtests.locale=sr_RS_#Latn -Dtests.timezone=America/Indiana/Vevay -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.00s | TestConfigSets (suite) <<<
[junit4] > Throwable #1: java.lang.AssertionError: ERROR: SolrIndexSearcher opens=4 closes=3
[junit4] > at __randomizedtesting.SeedInfo.seed([8E986FDB0F0B3AE0]:0)
[junit4] > at org.apache.solr.SolrTestCaseJ4.endTrackingSearchers(SolrTestCaseJ4.java:412)
[junit4] > at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:176)
[junit4] > at java.lang.Thread.run(Thread.java:744)
[junit4] Completed in 136.71s, 3 tests, 2 failures <<< FAILURES!
[...truncated 646 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:490: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1276: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:908: There were test failures: 379 suites, 1601 tests, 1 suite-level error, 1 error, 1 failure, 42 ignored (21 assumptions)
Total time: 85 minutes 33 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_60-ea-b10 -XX:+UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure