You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2014/05/24 03:54:50 UTC
[JENKINS] Lucene-Solr-Tests-4.x-Java7 - Build # 1991 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java7/1991/
2 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch
Error Message:
shard2 is not consistent. Got 137 from http://127.0.0.1:63835/collection1lastClient and got 124 from http://127.0.0.1:20111/collection1
Stack Trace:
java.lang.AssertionError: shard2 is not consistent. Got 137 from http://127.0.0.1:63835/collection1lastClient and got 124 from http://127.0.0.1:20111/collection1
at __randomizedtesting.SeedInfo.seed([7D4E18A426FFD2C9:FCA896BC51A0B2F5]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1139)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1118)
at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.doTest(ChaosMonkeySafeLeaderTest.java:150)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
at sun.reflect.GeneratedMethodAccessor36.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:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
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:65)
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:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
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:65)
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:360)
at java.lang.Thread.run(Thread.java:724)
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([7D4E18A426FFD2C9:79469757345A3DE8]:0)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
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:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
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:65)
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:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
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:65)
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:360)
at java.lang.Thread.run(Thread.java:724)
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)
... 47 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:432)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
... 48 more
Build Log:
[...truncated 11154 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./solr.cloud.OverseerTest-7D4E18A426FFD2C9-001/init-core-data-001
[junit4] 2> 1202390 T3310 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
[junit4] 2> 1202391 T3310 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 1202391 T3310 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1202397 T3310 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment
[junit4] 2> 1202398 T3310 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1202399 T3311 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1202500 T3310 oasc.ZkTestServer.run start zk server on port:36919
[junit4] 2> 1202501 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1202504 T3317 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@72375079 name:ZooKeeperConnection Watcher:127.0.0.1:36919 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1202505 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1202507 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1202522 T3319 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b297517 name:ZooKeeperConnection Watcher:127.0.0.1:36919 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1202522 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1202522 T3310 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1202526 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1202528 T3321 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e15887c name:ZooKeeperConnection Watcher:127.0.0.1:36919/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1202528 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1202529 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1202531 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1202533 T3323 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@442d19ae name:ZooKeeperConnection Watcher:127.0.0.1:36919/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1202533 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1202534 T3310 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1202536 T3310 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1202541 T3310 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:36919_solr
[junit4] 2> 1202541 T3310 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1202543 T3310 oasc.Overseer.start Overseer (id=91808940561137667-127.0.0.1:36919_solr-n_0000000000) starting
[junit4] 2> 1202545 T3310 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1202548 T3310 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1202551 T3310 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1202554 T3310 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1202557 T3310 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1202561 T3310 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1202566 T3325 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1202566 T3310 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1202567 T3324 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1202569 T3310 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1202570 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1202573 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1202575 T3327 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@57796a5f name:ZooKeeperConnection Watcher:127.0.0.1:36919/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1202575 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1202576 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1202578 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 1202581 T3327 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1202581 T3321 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1202583 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1202584 T3324 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1202585 T3324 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> 1202585 T3324 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 1202586 T3324 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1202588 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1202589 T3327 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> 1202589 T3321 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> 1203084 T3310 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1203105 T3310 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1203110 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1203112 T3324 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1203112 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1203115 T3324 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> 1203115 T3324 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1203116 T3324 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 1203118 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1203220 T3321 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> 1203220 T3327 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> 1203613 T3310 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 1203630 T3310 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 1203634 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1203635 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1203635 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1203636 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1203636 T3324 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1203640 T3324 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> 1203640 T3324 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1203640 T3324 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1203643 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1203745 T3327 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> 1203745 T3321 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> 1204137 T3310 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1204155 T3310 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1204159 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1204160 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1204160 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1204161 T3324 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1204161 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1204165 T3324 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node4",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1204165 T3324 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1204166 T3324 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1204168 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1204270 T3321 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> 1204270 T3327 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> 1204662 T3310 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1204679 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1204680 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1204680 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1204681 T3324 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1204681 T3324 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core5",
[junit4] 2> "core_node_name":"node5",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1204682 T3324 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1204682 T3324 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 1204684 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1204787 T3327 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> 1204787 T3321 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> 1205180 T3310 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 1205198 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1205198 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1205199 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1205200 T3324 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1205201 T3324 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core6",
[junit4] 2> "core_node_name":"node6",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1205201 T3324 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1205201 T3324 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1205204 T3323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1205306 T3321 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> 1205306 T3327 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> 1205699 T3310 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1205715 T3327 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1205729 T3310 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:36919 36919
[junit4] 2> 1205795 T3311 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:36919 36919
[junit4] 2> 1205797 T3310 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
[junit4] 2> 1205798 T3324 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:36919_solr
[junit4] 2> 1205799 T3328 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[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:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[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:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 1205807 T3310 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
[junit4] 2> 1205808 T3310 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1205809 T3329 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1205910 T3310 oasc.ZkTestServer.run start zk server on port:36925
[junit4] 2> 1205911 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1205915 T3335 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@400d13b5 name:ZooKeeperConnection Watcher:127.0.0.1:36925/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1205915 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1205916 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1205918 T3337 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@770ffcab name:ZooKeeperConnection Watcher:127.0.0.1:36925 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1205918 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1205955 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1205957 T3339 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4edeb0f1 name:ZooKeeperConnection Watcher:127.0.0.1:36925 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1205958 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1205958 T3310 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1206004 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1206027 T3310 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1206030 T3310 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1206031 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1206034 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1206036 T3341 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@758e5f84 name:ZooKeeperConnection Watcher:127.0.0.1:36925/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1206036 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1206037 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1206039 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1206041 T3335 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1206041 T3341 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1206042 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1206043 T3343 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@936e5c4 name:ZooKeeperConnection Watcher:127.0.0.1:36925/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1206044 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1206045 T3310 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1206047 T3310 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1206059 T3310 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:36925_solr
[junit4] 2> 1206059 T3310 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1206090 T3310 oasc.Overseer.start Overseer (id=91808940784615428-127.0.0.1:36925_solr-n_0000000000) starting
[junit4] 2> 1206093 T3310 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1206105 T3310 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1206108 T3310 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1206111 T3310 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1206114 T3310 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1206117 T3310 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1206123 T3345 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1206123 T3344 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1206125 T3344 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1206126 T3344 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> 1206126 T3344 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1206127 T3344 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1206129 T3343 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1206131 T3341 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> 1206131 T3335 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> 1206626 T3310 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1206653 T3310 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1206660 T3343 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1206660 T3310 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1206661 T3344 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1206670 T3335 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1206670 T3341 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1206673 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1206673 T3343 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1206674 T3347 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@39fe2ec7 name:ZooKeeperConnection Watcher:127.0.0.1:36925/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1206675 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1206676 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1206678 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1206680 T3335 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1206680 T3347 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1206682 T3343 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1206682 T3310 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1206683 T3344 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> 1206684 T3344 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1206686 T3343 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1206688 T3310 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1206692 T3343 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1206695 T3343 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1206798 T3347 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> 1206798 T3335 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> 1206798 T3310 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1206811 T3335 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1206811 T3347 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1206819 T3310 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:36925 36925
[junit4] 2> 1207163 T3329 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:36925 36925
[junit4] 2> 1207165 T3310 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 2> 1207165 T3344 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:36925_solr
[junit4] 2> 1207167 T3348 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[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:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[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:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 1207175 T3310 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignmentBigger
[junit4] 2> 1207176 T3310 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1207177 T3349 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1207217 T3327 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 1207217 T3327 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 1207218 T3327 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard3/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 1207278 T3310 oasc.ZkTestServer.run start zk server on port:36932
[junit4] 2> 1207279 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207282 T3355 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16794502 name:ZooKeeperConnection Watcher:127.0.0.1:36932 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207282 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207285 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207293 T3357 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4992a59b name:ZooKeeperConnection Watcher:127.0.0.1:36932 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207293 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207294 T3310 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1207298 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207307 T3359 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2049671e name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207307 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207308 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1207311 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207312 T3361 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b161905 name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207312 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207313 T3310 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1207315 T3310 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1207319 T3310 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:36932_solr
[junit4] 2> 1207320 T3310 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1207322 T3310 oasc.Overseer.start Overseer (id=91808940874334211-127.0.0.1:36932_solr-n_0000000000) starting
[junit4] 2> 1207324 T3310 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1207327 T3310 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1207330 T3310 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1207333 T3310 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1207336 T3310 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1207339 T3310 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1207345 T3363 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1207345 T3310 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1207345 T3362 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1207347 T3310 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1207349 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207351 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207352 T3365 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7bb4eb07 name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207353 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207354 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207356 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node0
[junit4] 2> 1207358 T3365 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1207358 T3359 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1207359 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207360 T3367 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@dcdcbd6 name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207360 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207362 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207363 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1207366 T3359 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1207366 T3365 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1207366 T3367 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1207366 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207368 T3369 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4929aacc name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207368 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207369 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207371 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1207373 T3365 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1207373 T3359 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1207373 T3369 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1207373 T3367 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1207374 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207375 T3371 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@66d0ae35 name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207375 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207377 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207378 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node3
[junit4] 2> 1207381 T3367 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1207381 T3365 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1207381 T3369 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1207381 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207381 T3371 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1207381 T3359 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1207383 T3373 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4d0da59f name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207383 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207384 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207386 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node4
[junit4] 2> 1207389 T3369 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1207389 T3359 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1207389 T3367 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1207389 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207389 T3373 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1207389 T3365 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1207389 T3371 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 1207391 T3375 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c9a9293 name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207391 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207392 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207394 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node5
[junit4] 2> 1207396 T3369 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 1207397 T3375 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 1207397 T3365 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 1207397 T3367 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 1207397 T3359 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 1207397 T3371 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 1207396 T3373 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4] 2> 1207397 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207399 T3377 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6a0c87e3 name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207399 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207401 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207402 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node6
[junit4] 2> 1207405 T3373 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 1207405 T3365 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 1207405 T3359 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 1207405 T3375 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 1207406 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207405 T3371 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 1207405 T3377 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 1207405 T3369 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 1207405 T3367 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4] 2> 1207407 T3379 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@574dde2b name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207408 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207409 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207411 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node7
[junit4] 2> 1207413 T3369 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 1207413 T3365 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 1207414 T3377 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 1207414 T3379 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 1207413 T3375 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 1207414 T3359 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 1207414 T3367 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 1207413 T3373 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 1207413 T3371 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4] 2> 1207414 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207416 T3381 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18f59994 name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207416 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207418 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207419 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node8
[junit4] 2> 1207422 T3367 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 1207422 T3369 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 1207422 T3359 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 1207422 T3375 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 1207422 T3371 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 1207422 T3381 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 1207422 T3377 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 1207422 T3365 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 1207422 T3379 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 1207422 T3373 oascc.ZkStateReader$3.process Updating live nodes... (9)
[junit4] 2> 1207424 T3383 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15db5bab name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207423 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207425 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207427 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207428 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node9
[junit4] 2> 1207431 T3377 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 1207431 T3375 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 1207431 T3369 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 1207432 T3373 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 1207431 T3381 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 1207431 T3365 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 1207431 T3359 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 1207431 T3367 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 1207431 T3383 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 1207431 T3371 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 1207431 T3379 oascc.ZkStateReader$3.process Updating live nodes... (10)
[junit4] 2> 1207433 T3385 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@316cc36e name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207432 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207435 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207436 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207437 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node10
[junit4] 2> 1207440 T3365 oascc.ZkStateReader$3.process Updating live nodes... (11)
[junit4] 2> 1207440 T3377 oascc.ZkStateReader$3.process Updating live nodes... (11)
[junit4] 2> 1207440 T3375 oascc.ZkStateReader$3.process Updating live nodes... (11)
[junit4] 2> 1207441 T3371 oascc.ZkStateReader$3.process Updating live nodes... (11)
[junit4] 2> 1207441 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207440 T3359 oascc.ZkStateReader$3.process Updating live nodes... (11)
[junit4] 2> 1207440 T3367 oascc.ZkStateReader$3.process Updating live nodes... (11)
[junit4] 2> 1207440 T3369 oascc.ZkStateReader$3.process Updating live nodes... (11)
[junit4] 2> 1207440 T3379 oascc.ZkStateReader$3.process Updating live nodes... (11)
[junit4] 2> 1207440 T3381 oascc.ZkStateReader$3.process Updating live nodes... (11)
[junit4] 2> 1207440 T3373 oascc.ZkStateReader$3.process Updating live nodes... (11)
[junit4] 2> 1207440 T3385 oascc.ZkStateReader$3.process Updating live nodes... (11)
[junit4] 2> 1207440 T3383 oascc.ZkStateReader$3.process Updating live nodes... (11)
[junit4] 2> 1207443 T3387 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@78d7ff1d name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207444 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207445 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207447 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node11
[junit4] 2> 1207449 T3371 oascc.ZkStateReader$3.process Updating live nodes... (12)
[junit4] 2> 1207449 T3387 oascc.ZkStateReader$3.process Updating live nodes... (12)
[junit4] 2> 1207450 T3367 oascc.ZkStateReader$3.process Updating live nodes... (12)
[junit4] 2> 1207450 T3385 oascc.ZkStateReader$3.process Updating live nodes... (12)
[junit4] 2> 1207450 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207450 T3375 oascc.ZkStateReader$3.process Updating live nodes... (12)
[junit4] 2> 1207450 T3369 oascc.ZkStateReader$3.process Updating live nodes... (12)
[junit4] 2> 1207450 T3383 oascc.ZkStateReader$3.process Updating live nodes... (12)
[junit4] 2> 1207449 T3359 oascc.ZkStateReader$3.process Updating live nodes... (12)
[junit4] 2> 1207452 T3389 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@79e4b57d name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207450 T3373 oascc.ZkStateReader$3.process Updating live nodes... (12)
[junit4] 2> 1207449 T3381 oascc.ZkStateReader$3.process Updating live nodes... (12)
[junit4] 2> 1207450 T3377 oascc.ZkStateReader$3.process Updating live nodes... (12)
[junit4] 2> 1207449 T3365 oascc.ZkStateReader$3.process Updating live nodes... (12)
[junit4] 2> 1207449 T3379 oascc.ZkStateReader$3.process Updating live nodes... (12)
[junit4] 2> 1207452 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207454 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207456 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node12
[junit4] 2> 1207459 T3373 oascc.ZkStateReader$3.process Updating live nodes... (13)
[junit4] 2> 1207459 T3385 oascc.ZkStateReader$3.process Updating live nodes... (13)
[junit4] 2> 1207459 T3359 oascc.ZkStateReader$3.process Updating live nodes... (13)
[junit4] 2> 1207459 T3371 oascc.ZkStateReader$3.process Updating live nodes... (13)
[junit4] 2> 1207459 T3379 oascc.ZkStateReader$3.process Updating live nodes... (13)
[junit4] 2> 1207459 T3377 oascc.ZkStateReader$3.process Updating live nodes... (13)
[junit4] 2> 1207459 T3369 oascc.ZkStateReader$3.process Updating live nodes... (13)
[junit4] 2> 1207459 T3365 oascc.ZkStateReader$3.process Updating live nodes... (13)
[junit4] 2> 1207459 T3381 oascc.ZkStateReader$3.process Updating live nodes... (13)
[junit4] 2> 1207459 T3387 oascc.ZkStateReader$3.process Updating live nodes... (13)
[junit4] 2> 1207459 T3375 oascc.ZkStateReader$3.process Updating live nodes... (13)
[junit4] 2> 1207459 T3383 oascc.ZkStateReader$3.process Updating live nodes... (13)
[junit4] 2> 1207459 T3389 oascc.ZkStateReader$3.process Updating live nodes... (13)
[junit4] 2> 1207459 T3367 oascc.ZkStateReader$3.process Updating live nodes... (13)
[junit4] 2> 1207461 T3391 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a0d58e8 name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207460 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207463 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207464 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207466 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node13
[junit4] 2> 1207468 T3375 oascc.ZkStateReader$3.process Updating live nodes... (14)
[junit4] 2> 1207469 T3387 oascc.ZkStateReader$3.process Updating live nodes... (14)
[junit4] 2> 1207469 T3391 oascc.ZkStateReader$3.process Updating live nodes... (14)
[junit4] 2> 1207469 T3371 oascc.ZkStateReader$3.process Updating live nodes... (14)
[junit4] 2> 1207469 T3369 oascc.ZkStateReader$3.process Updating live nodes... (14)
[junit4] 2> 1207469 T3383 oascc.ZkStateReader$3.process Updating live nodes... (14)
[junit4] 2> 1207469 T3381 oascc.ZkStateReader$3.process Updating live nodes... (14)
[junit4] 2> 1207469 T3389 oascc.ZkStateReader$3.process Updating live nodes... (14)
[junit4] 2> 1207469 T3373 oascc.ZkStateReader$3.process Updating live nodes... (14)
[junit4] 2> 1207469 T3385 oascc.ZkStateReader$3.process Updating live nodes... (14)
[junit4] 2> 1207469 T3377 oascc.ZkStateReader$3.process Updating live nodes... (14)
[junit4] 2> 1207470 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207469 T3365 oascc.ZkStateReader$3.process Updating live nodes... (14)
[junit4] 2> 1207469 T3379 oascc.ZkStateReader$3.process Updating live nodes... (14)
[junit4] 2> 1207469 T3359 oascc.ZkStateReader$3.process Updating live nodes... (14)
[junit4] 2> 1207469 T3367 oascc.ZkStateReader$3.process Updating live nodes... (14)
[junit4] 2> 1207471 T3393 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e3ae894 name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207473 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207474 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207476 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node14
[junit4] 2> 1207478 T3379 oascc.ZkStateReader$3.process Updating live nodes... (15)
[junit4] 2> 1207479 T3381 oascc.ZkStateReader$3.process Updating live nodes... (15)
[junit4] 2> 1207479 T3359 oascc.ZkStateReader$3.process Updating live nodes... (15)
[junit4] 2> 1207479 T3389 oascc.ZkStateReader$3.process Updating live nodes... (15)
[junit4] 2> 1207479 T3373 oascc.ZkStateReader$3.process Updating live nodes... (15)
[junit4] 2> 1207479 T3367 oascc.ZkStateReader$3.process Updating live nodes... (15)
[junit4] 2> 1207479 T3393 oascc.ZkStateReader$3.process Updating live nodes... (15)
[junit4] 2> 1207479 T3383 oascc.ZkStateReader$3.process Updating live nodes... (15)
[junit4] 2> 1207479 T3375 oascc.ZkStateReader$3.process Updating live nodes... (15)
[junit4] 2> 1207479 T3369 oascc.ZkStateReader$3.process Updating live nodes... (15)
[junit4] 2> 1207479 T3385 oascc.ZkStateReader$3.process Updating live nodes... (15)
[junit4] 2> 1207479 T3377 oascc.ZkStateReader$3.process Updating live nodes... (15)
[junit4] 2> 1207479 T3371 oascc.ZkStateReader$3.process Updating live nodes... (15)
[junit4] 2> 1207479 T3365 oascc.ZkStateReader$3.process Updating live nodes... (15)
[junit4] 2> 1207479 T3391 oascc.ZkStateReader$3.process Updating live nodes... (15)
[junit4] 2> 1207479 T3387 oascc.ZkStateReader$3.process Updating live nodes... (15)
[junit4] 2> 1207481 T3395 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e3ad722 name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207480 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207483 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207484 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207486 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node15
[junit4] 2> 1207489 T3383 oascc.ZkStateReader$3.process Updating live nodes... (16)
[junit4] 2> 1207489 T3389 oascc.ZkStateReader$3.process Updating live nodes... (16)
[junit4] 2> 1207489 T3371 oascc.ZkStateReader$3.process Updating live nodes... (16)
[junit4] 2> 1207490 T3391 oascc.ZkStateReader$3.process Updating live nodes... (16)
[junit4] 2> 1207490 T3379 oascc.ZkStateReader$3.process Updating live nodes... (16)
[junit4] 2> 1207489 T3369 oascc.ZkStateReader$3.process Updating live nodes... (16)
[junit4] 2> 1207489 T3365 oascc.ZkStateReader$3.process Updating live nodes... (16)
[junit4] 2> 1207489 T3373 oascc.ZkStateReader$3.process Updating live nodes... (16)
[junit4] 2> 1207489 T3359 oascc.ZkStateReader$3.process Updating live nodes... (16)
[junit4] 2> 1207489 T3387 oascc.ZkStateReader$3.process Updating live nodes... (16)
[junit4] 2> 1207489 T3381 oascc.ZkStateReader$3.process Updating live nodes... (16)
[junit4] 2> 1207492 T3397 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@689a16dd name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207489 T3367 oascc.ZkStateReader$3.process Updating live nodes... (16)
[junit4] 2> 1207489 T3375 oascc.ZkStateReader$3.process Updating live nodes... (16)
[junit4] 2> 1207489 T3393 oascc.ZkStateReader$3.process Updating live nodes... (16)
[junit4] 2> 1207489 T3377 oascc.ZkStateReader$3.process Updating live nodes... (16)
[junit4] 2> 1207489 T3385 oascc.ZkStateReader$3.process Updating live nodes... (16)
[junit4] 2> 1207489 T3395 oascc.ZkStateReader$3.process Updating live nodes... (16)
[junit4] 2> 1207490 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207494 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207495 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207497 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node16
[junit4] 2> 1207500 T3379 oascc.ZkStateReader$3.process Updating live nodes... (17)
[junit4] 2> 1207500 T3381 oascc.ZkStateReader$3.process Updating live nodes... (17)
[junit4] 2> 1207500 T3383 oascc.ZkStateReader$3.process Updating live nodes... (17)
[junit4] 2> 1207501 T3367 oascc.ZkStateReader$3.process Updating live nodes... (17)
[junit4] 2> 1207501 T3397 oascc.ZkStateReader$3.process Updating live nodes... (17)
[junit4] 2> 1207500 T3389 oascc.ZkStateReader$3.process Updating live nodes... (17)
[junit4] 2> 1207500 T3373 oascc.ZkStateReader$3.process Updating live nodes... (17)
[junit4] 2> 1207500 T3395 oascc.ZkStateReader$3.process Updating live nodes... (17)
[junit4] 2> 1207500 T3385 oascc.ZkStateReader$3.process Updating live nodes... (17)
[junit4] 2> 1207500 T3393 oascc.ZkStateReader$3.process Updating live nodes... (17)
[junit4] 2> 1207500 T3359 oascc.ZkStateReader$3.process Updating live nodes... (17)
[junit4] 2> 1207500 T3365 oascc.ZkStateReader$3.process Updating live nodes... (17)
[junit4] 2> 1207500 T3375 oascc.ZkStateReader$3.process Updating live nodes... (17)
[junit4] 2> 1207500 T3377 oascc.ZkStateReader$3.process Updating live nodes... (17)
[junit4] 2> 1207500 T3371 oascc.ZkStateReader$3.process Updating live nodes... (17)
[junit4] 2> 1207500 T3369 oascc.ZkStateReader$3.process Updating live nodes... (17)
[junit4] 2> 1207500 T3387 oascc.ZkStateReader$3.process Updating live nodes... (17)
[junit4] 2> 1207500 T3391 oascc.ZkStateReader$3.process Updating live nodes... (17)
[junit4] 2> 1207503 T3399 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b072e37 name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207501 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207505 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207506 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207508 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node17
[junit4] 2> 1207511 T3379 oascc.ZkStateReader$3.process Updating live nodes... (18)
[junit4] 2> 1207511 T3391 oascc.ZkStateReader$3.process Updating live nodes... (18)
[junit4] 2> 1207511 T3377 oascc.ZkStateReader$3.process Updating live nodes... (18)
[junit4] 2> 1207511 T3385 oascc.ZkStateReader$3.process Updating live nodes... (18)
[junit4] 2> 1207511 T3383 oascc.ZkStateReader$3.process Updating live nodes... (18)
[junit4] 2> 1207512 T3389 oascc.ZkStateReader$3.process Updating live nodes... (18)
[junit4] 2> 1207512 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207511 T3367 oascc.ZkStateReader$3.process Updating live nodes... (18)
[junit4] 2> 1207511 T3393 oascc.ZkStateReader$3.process Updating live nodes... (18)
[junit4] 2> 1207511 T3397 oascc.ZkStateReader$3.process Updating live nodes... (18)
[junit4] 2> 1207511 T3373 oascc.ZkStateReader$3.process Updating live nodes... (18)
[junit4] 2> 1207511 T3399 oascc.ZkStateReader$3.process Updating live nodes... (18)
[junit4] 2> 1207511 T3375 oascc.ZkStateReader$3.process Updating live nodes... (18)
[junit4] 2> 1207511 T3395 oascc.ZkStateReader$3.process Updating live nodes... (18)
[junit4] 2> 1207511 T3371 oascc.ZkStateReader$3.process Updating live nodes... (18)
[junit4] 2> 1207511 T3369 oascc.ZkStateReader$3.process Updating live nodes... (18)
[junit4] 2> 1207511 T3365 oascc.ZkStateReader$3.process Updating live nodes... (18)
[junit4] 2> 1207511 T3359 oascc.ZkStateReader$3.process Updating live nodes... (18)
[junit4] 2> 1207511 T3387 oascc.ZkStateReader$3.process Updating live nodes... (18)
[junit4] 2> 1207511 T3381 oascc.ZkStateReader$3.process Updating live nodes... (18)
[junit4] 2> 1207513 T3401 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@28b81469 name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207516 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207517 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207519 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node18
[junit4] 2> 1207521 T3401 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207521 T3369 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207522 T3379 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207522 T3387 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207522 T3395 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207523 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207523 T3375 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207523 T3377 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207523 T3385 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207522 T3397 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207524 T3403 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@113fdab4 name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207522 T3373 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207522 T3399 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207522 T3367 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207522 T3381 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207522 T3383 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207522 T3393 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207522 T3389 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207522 T3371 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207522 T3359 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207522 T3391 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207522 T3365 oascc.ZkStateReader$3.process Updating live nodes... (19)
[junit4] 2> 1207525 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207528 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207530 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node19
[junit4] 2> 1207533 T3369 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207533 T3365 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207533 T3385 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207534 T3395 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207534 T3397 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207534 T3371 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207534 T3389 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207534 T3383 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207534 T3393 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207534 T3391 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207533 T3387 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207533 T3399 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207533 T3379 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207533 T3373 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207533 T3381 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207533 T3359 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207533 T3401 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207536 T3405 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2517386f name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207534 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207534 T3403 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207534 T3367 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207534 T3377 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207534 T3375 oascc.ZkStateReader$3.process Updating live nodes... (20)
[junit4] 2> 1207538 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207540 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207542 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node20
[junit4] 2> 1207545 T3369 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207545 T3381 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207545 T3395 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207546 T3391 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207546 T3389 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207546 T3375 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207546 T3377 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207547 T3310 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1207546 T3397 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207546 T3403 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207546 T3405 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207546 T3367 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207546 T3393 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207546 T3399 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207546 T3373 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207545 T3383 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207545 T3385 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207545 T3379 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207545 T3371 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207545 T3387 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207545 T3359 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207545 T3365 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207545 T3401 oascc.ZkStateReader$3.process Updating live nodes... (21)
[junit4] 2> 1207548 T3407 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5416734b name:ZooKeeperConnection Watcher:127.0.0.1:36932/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1207551 T3310 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1207552 T3310 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1207554 T3310 oascc.SolrZkClient.makePath makePath: /live_nodes/node21
[junit4] 2> 1207557 T3375 oascc.ZkStateReader$3.process Updating live nodes... (22)
[junit4] 2> 1207557 T3373 oascc.ZkStateReader$3.process Updating live nodes... (22)
[junit4] 2> 1207557 T3389 oascc.ZkStateReader$3.process Updating live nodes... (22)
[junit4] 2> 1207558 T3379 oascc.ZkStateReader$3.process Updating live nodes... (22)
[junit4] 2> 1207558 T3371 oascc.ZkStateReader$3.process Updating live nodes... (22)
[junit4] 2> 1207558 T3369 oascc.ZkStateReader$3.process Updating live nodes... (22)
[junit4] 2> 1207558 T3391 oascc.ZkStateReader$3.process Updating live nodes... (22)
[junit4] 2> 1207557 T3377 oascc.ZkStateReader$3.process Updating live nodes... (22)
[junit4] 2> 1207558 T3387 oascc.ZkStateReader$3.process Updating live nodes... (22)
[
[...truncated too long message...]
] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 4011098 T5466 C900 P38419 oasc.SyncStrategy.sync WARN Closed, skipping sync up.
[junit4] 2> 4011098 T5466 oasc.ShardLeaderElectionContext.rejoinLeaderElection Not rejoining election because CoreContainer is shutdown
[junit4] 2> 4011098 T5466 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@419de1c3
[junit4] 2> 4011100 T5466 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=23,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=178,cumulative_deletesById=76,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=11605,transaction_logs_total_number=1}
[junit4] 2> 4011101 T5466 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 4011101 T5466 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 4011101 T5466 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 4011102 T5466 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 4011103 T5466 oasc.CachingDirectoryFactory.close Closing StandardDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 4011104 T5466 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-7D4E18A426FFD2C9-001/tempDir-001/jetty12/index.20140523172442246 [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-7D4E18A426FFD2C9-001/tempDir-001/jetty12/index.20140523172442246;done=false>>]
[junit4] 2> 4011104 T5466 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-7D4E18A426FFD2C9-001/tempDir-001/jetty12/index.20140523172442246
[junit4] 2> 4011104 T5466 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-7D4E18A426FFD2C9-001/tempDir-001/jetty12 [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-7D4E18A426FFD2C9-001/tempDir-001/jetty12;done=false>>]
[junit4] 2> 4011105 T5466 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-7D4E18A426FFD2C9-001/tempDir-001/jetty12
[junit4] 2> 4011105 T5466 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 4011105 T5466 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-7D4E18A426FFD2C9-001
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=ca_ES, timezone=SystemV/PST8
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=197718768,total=533725184
[junit4] 2> NOTE: All tests run in this JVM: [DocValuesTest, TestFieldSortValues, DeleteShardTest, AddBlockUpdateTest, ZkControllerTest, TestMaxScoreQueryParser, TestDynamicFieldCollectionResource, TestDefaultSearchFieldResource, IndexBasedSpellCheckerTest, TestManagedSchemaFieldResource, URLClassifyProcessorTest, TestAnalyzeInfixSuggestions, TestManagedSchema, DistanceFunctionTest, TestCoreContainer, TestTrie, BlockCacheTest, CacheHeaderTest, DistributedExpandComponentTest, TestAnalyzedSuggestions, NotRequiredUniqueKeyTest, TestStandardQParsers, IndexSchemaTest, TestDocBasedVersionConstraints, CoreAdminRequestStatusTest, TestAddFieldRealTimeGet, ResponseHeaderTest, DateFieldTest, FileBasedSpellCheckerTest, RequestHandlersTest, HdfsRecoveryZkTest, ChaosMonkeyNothingIsSafeTest, StatsComponentTest, TestDFRSimilarityFactory, AtomicUpdatesTest, TestSearcherReuse, TestCloudManagedSchema, SolrCoreCheckLockOnStartupTest, CursorMarkTest, LukeRequestHandlerTest, DistributedTermsComponentTest, TestRecovery, TestCollationFieldDocValues, ShardSplitTest, RecoveryZkTest, TestLMJelinekMercerSimilarityFactory, TestCollationField, SSLMigrationTest, SolrIndexSplitterTest, TestCharFilters, SpellPossibilityIteratorTest, XmlUpdateRequestHandlerTest, SoftAutoCommitTest, OverseerCollectionProcessorTest, DistributedQueryComponentOptimizationTest, DeleteInactiveReplicaTest, TestIndexSearcher, TestSystemIdResolver, AutoCommitTest, TestHighFrequencyDictionaryFactory, SliceStateTest, SignatureUpdateProcessorFactoryTest, AnalysisErrorHandlingTest, ShardRoutingTest, LoggingHandlerTest, TestQuerySenderNoQuery, PathHierarchyTokenizerFactoryTest, TestStressLucene, HdfsUnloadDistributedZkTest, DistributedSuggestComponentTest, FieldAnalysisRequestHandlerTest, TestSweetSpotSimilarityFactory, TestRangeQuery, StandardRequestHandlerTest, OpenExchangeRatesOrgProviderTest, UnloadDistributedZkTest, TestCursorMarkWithoutUniqueKey, SuggesterWFSTTest, TestLazyCores, TestQueryTypes, OverseerTest, TestPartialUpdateDeduplication, TestSolrXmlPersistor, TestSuggestSpellingConverter, BasicFunctionalityTest, BadComponentTest, RegexBoostProcessorTest, OverseerStatusTest, TestFastOutputStream, SpellCheckComponentTest, TestSolrXmlPersistence, TestCollectionAPI, TestAtomicUpdateErrorCases, TestSolrIndexConfig, UUIDFieldTest, LeaderElectionIntegrationTest, HttpPartitionTest, SyncSliceTest, BasicDistributedZk2Test, ChaosMonkeySafeLeaderTest]
[junit4] Completed on J1 in 1456.24s, 1 test, 1 failure <<< FAILURES!
[...truncated 565 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:467: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:447: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:45: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/common-build.xml:496: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:1297: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:921: There were test failures: 396 suites, 1640 tests, 1 error, 1 failure, 36 ignored (15 assumptions)
Total time: 113 minutes 3 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-Tests-4.x-Java7 - Build # 1992 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java7/1992/
3 tests failed.
REGRESSION: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch
Error Message:
Test abandoned because suite timeout was reached.
Stack Trace:
java.lang.Exception: Test abandoned because suite timeout was reached.
at __randomizedtesting.SeedInfo.seed([8BD0FFE29E754FA]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.CollectionsAPIDistributedZkTest
Error Message:
Suite timeout exceeded (>= 7200000 msec).
Stack Trace:
java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
at __randomizedtesting.SeedInfo.seed([8BD0FFE29E754FA]:0)
REGRESSION: org.apache.solr.cloud.HttpPartitionTest.testDistribSearch
Error Message:
No registered leader was found after waiting for 60000ms , collection: c8n_1x3_lf slice: shard1
Stack Trace:
org.apache.solr.common.SolrException: No registered leader was found after waiting for 60000ms , collection: c8n_1x3_lf slice: shard1
at __randomizedtesting.SeedInfo.seed([8BD0FFE29E754FA:895B81E65EB834C6]:0)
at org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:545)
at org.apache.solr.cloud.HttpPartitionTest.testRf3WithLeaderFailover(HttpPartitionTest.java:349)
at org.apache.solr.cloud.HttpPartitionTest.doTest(HttpPartitionTest.java:148)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
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:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
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:65)
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:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
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:65)
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:360)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 11021 lines...]
[junit4] Suite: org.apache.solr.cloud.HttpPartitionTest
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/init-core-data-001
[junit4] 2> 1447103 T17585 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_yrr/z
[junit4] 2> 1447108 T17585 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 1447109 T17585 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1447110 T17586 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1447210 T17585 oasc.ZkTestServer.run start zk server on port:33211
[junit4] 2> 1447211 T17585 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1447218 T17592 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2baf239f name:ZooKeeperConnection Watcher:127.0.0.1:33211 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1447218 T17585 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1447219 T17585 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1447223 T17585 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1447225 T17594 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6334cc6a name:ZooKeeperConnection Watcher:127.0.0.1:33211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1447225 T17585 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1447226 T17585 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1447229 T17585 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1447231 T17585 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1447240 T17585 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1447242 T17585 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1447243 T17585 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1447253 T17585 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 1447254 T17585 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1447357 T17585 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1447358 T17585 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1447360 T17585 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1447361 T17585 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1447363 T17585 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1447364 T17585 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1447371 T17585 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1447372 T17585 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1447374 T17585 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 1447375 T17585 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 1447378 T17585 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1447378 T17585 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1447381 T17585 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1447381 T17585 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1447388 T17585 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1447389 T17585 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1447391 T17585 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1447392 T17585 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1448362 T17585 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1448366 T17585 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:33215
[junit4] 2> 1448367 T17585 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1448367 T17585 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1448367 T17585 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-002
[junit4] 2> 1448368 T17585 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-002/'
[junit4] 2> 1448398 T17585 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-002/solr.xml
[junit4] 2> 1448471 T17585 oasc.CoreContainer.<init> New CoreContainer 1252417894
[junit4] 2> 1448472 T17585 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-002/]
[junit4] 2> 1448473 T17585 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1448474 T17585 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1448474 T17585 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1448474 T17585 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1448475 T17585 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1448475 T17585 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1448475 T17585 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1448475 T17585 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1448476 T17585 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1448476 T17585 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1448477 T17585 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1448477 T17585 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1448478 T17585 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33211/solr
[junit4] 2> 1448478 T17585 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1448479 T17585 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1448481 T17605 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@714495d3 name:ZooKeeperConnection Watcher:127.0.0.1:33211 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1448482 T17585 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1448500 T17585 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1448502 T17607 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ff4d48f name:ZooKeeperConnection Watcher:127.0.0.1:33211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1448502 T17585 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1448504 T17585 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1448516 T17585 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1448520 T17585 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1448523 T17585 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1448534 T17585 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1448542 T17585 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1448544 T17585 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33214__yrr%2Fz
[junit4] 2> 1448545 T17585 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:33214__yrr%2Fz
[junit4] 2> 1448548 T17585 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1448555 T17585 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1448565 T17585 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:33214__yrr%2Fz
[junit4] 2> 1448565 T17585 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1448567 T17585 oasc.Overseer.start Overseer (id=91819433250848771-127.0.0.1:33214__yrr%2Fz-n_0000000000) starting
[junit4] 2> 1448583 T17585 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1448605 T17609 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1448606 T17585 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1448607 T17585 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1448609 T17585 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1448610 T17608 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1448615 T17610 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 1448615 T17610 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1448617 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1448617 T17610 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1448618 T17608 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1448618 T17608 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:33214/_yrr/z",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:33214__yrr%2Fz",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1448618 T17608 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 1448618 T17608 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1448620 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1448621 T17607 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> 1449618 T17610 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1449618 T17610 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1449619 T17610 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1449619 T17610 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1449620 T17610 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1449620 T17610 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-002/collection1/'
[junit4] 2> 1449622 T17610 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-002/collection1/lib/README' to classloader
[junit4] 2> 1449622 T17610 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-002/collection1/lib/classes/' to classloader
[junit4] 2> 1449623 T17610 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-002/collection1/lib/.svn/' to classloader
[junit4] 2> 1449704 T17610 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
[junit4] 2> 1449784 T17610 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1449885 T17610 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1449898 T17610 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1450634 T17610 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1450634 T17610 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1450635 T17610 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1450649 T17610 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1450653 T17610 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1450665 T17610 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1450670 T17610 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1450674 T17610 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1450675 T17610 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1450675 T17610 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1450676 T17610 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1450677 T17610 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1450677 T17610 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1450677 T17610 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 1450677 T17610 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1450678 T17610 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-002/collection1/, dataDir=./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-001/control/data/
[junit4] 2> 1450678 T17610 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fc2aa1f
[junit4] 2> 1450679 T17610 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-001/control/data
[junit4] 2> 1450679 T17610 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-001/control/data/index/
[junit4] 2> 1450680 T17610 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1450680 T17610 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-001/control/data/index
[junit4] 2> 1450681 T17610 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=42.9248046875, floorSegmentMB=1.103515625, forceMergeDeletesPctAllowed=19.97506321927009, segmentsPerTier=35.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1450682 T17610 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@67bff5fa lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4f1651f1),segFN=segments_1,generation=1}
[junit4] 2> 1450682 T17610 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1450687 T17610 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1450687 T17610 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1450688 T17610 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1450688 T17610 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1450688 T17610 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1450689 T17610 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1450689 T17610 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1450690 T17610 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1450690 T17610 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1450691 T17610 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1450691 T17610 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1450691 T17610 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1450692 T17610 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1450692 T17610 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1450693 T17610 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1450693 T17610 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1450710 T17610 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1450717 T17610 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1450717 T17610 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1450718 T17610 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=25, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1450718 T17610 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@67bff5fa lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4f1651f1),segFN=segments_1,generation=1}
[junit4] 2> 1450719 T17610 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1450719 T17610 oass.SolrIndexSearcher.<init> Opening Searcher@15217e26[collection1] main
[junit4] 2> 1450719 T17610 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1450720 T17610 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1450721 T17610 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 1450721 T17610 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1450721 T17610 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 1450722 T17610 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1450722 T17610 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 1450723 T17610 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1450723 T17610 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 1450723 T17610 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 1450726 T17611 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@15217e26[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1450729 T17610 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1450730 T17614 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:33214/_yrr/z collection:control_collection shard:shard1
[junit4] 2> 1450730 T17585 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1
[junit4] 2> 1450731 T17614 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1450731 T17585 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1450736 T17585 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1450750 T17617 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15d2ab34 name:ZooKeeperConnection Watcher:127.0.0.1:33211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1450750 T17585 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1450751 T17585 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1450752 T17614 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1450754 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1450754 T17585 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 1450754 T17614 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1450755 T17614 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1450755 T17608 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> ASYNC NEW_CORE C1211 name=collection1 org.apache.solr.core.SolrCore@4b5d4bf0 url=http://127.0.0.1:33214/_yrr/z/collection1 node=127.0.0.1:33214__yrr%2Fz C1211_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:33214/_yrr/z, core=collection1, node_name=127.0.0.1:33214__yrr%2Fz}
[junit4] 2> 1450755 T17614 C1211 P33214 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:33214/_yrr/z/collection1/
[junit4] 2> 1450756 T17614 C1211 P33214 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1450756 T17614 C1211 P33214 oasc.SyncStrategy.syncToMe http://127.0.0.1:33214/_yrr/z/collection1/ has no replicas
[junit4] 2> 1450756 T17614 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:33214/_yrr/z/collection1/ shard1
[junit4] 2> 1450757 T17614 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1450757 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1450758 T17607 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> 1450758 T17617 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> 1450762 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1450763 T17608 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1450765 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1450868 T17607 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> 1450868 T17617 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> 1450915 T17614 oasc.ZkController.register We are http://127.0.0.1:33214/_yrr/z/collection1/ and leader is http://127.0.0.1:33214/_yrr/z/collection1/
[junit4] 2> 1450915 T17614 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:33214/_yrr/z
[junit4] 2> 1450915 T17614 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1450915 T17614 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 1450916 T17614 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1450917 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1450917 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1450917 T17614 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1450918 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1450918 T17608 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1450919 T17608 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:33214/_yrr/z",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:33214__yrr%2Fz",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1450927 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1451031 T17607 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> 1451031 T17617 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> 1451744 T17585 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 1451745 T17585 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1451748 T17585 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:33220
[junit4] 2> 1451748 T17585 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1451749 T17585 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1451749 T17585 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-003
[junit4] 2> 1451749 T17585 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-003/'
[junit4] 2> 1451780 T17585 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-003/solr.xml
[junit4] 2> 1451854 T17585 oasc.CoreContainer.<init> New CoreContainer 1774569388
[junit4] 2> 1451855 T17585 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-003/]
[junit4] 2> 1451856 T17585 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1451856 T17585 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1451857 T17585 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1451857 T17585 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1451857 T17585 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1451858 T17585 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1451858 T17585 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1451858 T17585 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1451859 T17585 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1451859 T17585 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1451860 T17585 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1451860 T17585 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1451860 T17585 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33211/solr
[junit4] 2> 1451861 T17585 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1451862 T17585 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1451872 T17628 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@37b82374 name:ZooKeeperConnection Watcher:127.0.0.1:33211 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1451872 T17585 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1451874 T17585 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1451889 T17630 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1689acb3 name:ZooKeeperConnection Watcher:127.0.0.1:33211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1451889 T17585 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1451904 T17585 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1452907 T17585 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33219__yrr%2Fz
[junit4] 2> 1452933 T17585 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:33219__yrr%2Fz
[junit4] 2> 1452936 T17630 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1452936 T17617 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1452936 T17607 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1452959 T17631 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 1452959 T17631 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1452960 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1452960 T17631 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1452960 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1452961 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1452962 T17608 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1452962 T17608 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:33219/_yrr/z",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:33219__yrr%2Fz",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1452963 T17608 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 1452963 T17608 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1452971 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1452972 T17630 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1452972 T17617 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1452972 T17607 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1453962 T17631 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1453962 T17631 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1453963 T17631 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1453963 T17631 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1453964 T17631 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1453964 T17631 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-003/collection1/'
[junit4] 2> 1453965 T17631 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-003/collection1/lib/README' to classloader
[junit4] 2> 1453966 T17631 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-003/collection1/lib/classes/' to classloader
[junit4] 2> 1453967 T17631 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-003/collection1/lib/.svn/' to classloader
[junit4] 2> 1454071 T17631 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
[junit4] 2> 1454153 T17631 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1454254 T17631 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1454267 T17631 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1454971 T17631 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1454972 T17631 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1454973 T17631 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1454984 T17631 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1454987 T17631 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1454997 T17631 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1455001 T17631 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1455004 T17631 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1455005 T17631 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1455005 T17631 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1455005 T17631 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1455006 T17631 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1455006 T17631 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1455007 T17631 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 1455007 T17631 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1455007 T17631 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-003/collection1/, dataDir=./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-001/jetty1/
[junit4] 2> 1455007 T17631 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fc2aa1f
[junit4] 2> 1455008 T17631 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-001/jetty1
[junit4] 2> 1455008 T17631 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-001/jetty1/index/
[junit4] 2> 1455009 T17631 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 1455009 T17631 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-001/jetty1/index
[junit4] 2> 1455009 T17631 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=42.9248046875, floorSegmentMB=1.103515625, forceMergeDeletesPctAllowed=19.97506321927009, segmentsPerTier=35.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1455010 T17631 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@3177d0a4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@395ae398),segFN=segments_1,generation=1}
[junit4] 2> 1455010 T17631 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1455015 T17631 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1455015 T17631 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1455016 T17631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1455016 T17631 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1455016 T17631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1455016 T17631 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1455017 T17631 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1455017 T17631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1455017 T17631 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1455018 T17631 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1455018 T17631 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1455018 T17631 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1455019 T17631 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1455019 T17631 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1455020 T17631 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1455020 T17631 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1455032 T17631 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1455055 T17631 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1455055 T17631 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1455056 T17631 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=25, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1455056 T17631 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@3177d0a4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@395ae398),segFN=segments_1,generation=1}
[junit4] 2> 1455057 T17631 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1455057 T17631 oass.SolrIndexSearcher.<init> Opening Searcher@7ae0bd2a[collection1] main
[junit4] 2> 1455057 T17631 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1455058 T17631 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1455058 T17631 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 1455059 T17631 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1455059 T17631 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 1455059 T17631 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1455060 T17631 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 1455060 T17631 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1455060 T17631 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 1455060 T17631 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 1455064 T17632 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7ae0bd2a[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1455067 T17631 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1455068 T17635 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:33219/_yrr/z collection:collection1 shard:shard1
[junit4] 2> 1455068 T17585 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1
[junit4] 2> 1455069 T17635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1455069 T17585 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1455087 T17635 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1455089 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1455089 T17635 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1455090 T17635 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1212 name=collection1 org.apache.solr.core.SolrCore@304c3211 url=http://127.0.0.1:33219/_yrr/z/collection1 node=127.0.0.1:33219__yrr%2Fz C1212_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:33219/_yrr/z, core=collection1, node_name=127.0.0.1:33219__yrr%2Fz}
[junit4] 2> 1455090 T17635 C1212 P33219 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:33219/_yrr/z/collection1/
[junit4] 2> 1455090 T17608 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1455090 T17635 C1212 P33219 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1455091 T17635 C1212 P33219 oasc.SyncStrategy.syncToMe http://127.0.0.1:33219/_yrr/z/collection1/ has no replicas
[junit4] 2> 1455091 T17635 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:33219/_yrr/z/collection1/ shard1
[junit4] 2> 1455091 T17635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1455093 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1455093 T17607 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1455093 T17630 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1455093 T17617 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1455096 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1455097 T17608 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1455099 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1455201 T17607 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1455201 T17630 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1455201 T17617 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1455250 T17635 oasc.ZkController.register We are http://127.0.0.1:33219/_yrr/z/collection1/ and leader is http://127.0.0.1:33219/_yrr/z/collection1/
[junit4] 2> 1455250 T17635 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:33219/_yrr/z
[junit4] 2> 1455250 T17635 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1455250 T17635 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 1455251 T17635 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1455252 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1455252 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1455252 T17635 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1455252 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1455253 T17608 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1455253 T17608 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:33219/_yrr/z",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:33219__yrr%2Fz",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1455263 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1455365 T17617 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1455365 T17630 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1455365 T17607 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1456177 T17585 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 1456178 T17585 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1456180 T17585 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:33224
[junit4] 2> 1456181 T17585 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1456181 T17585 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1456181 T17585 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-004
[junit4] 2> 1456182 T17585 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-004/'
[junit4] 2> 1456213 T17585 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-004/solr.xml
[junit4] 2> 1456287 T17585 oasc.CoreContainer.<init> New CoreContainer 886170678
[junit4] 2> 1456287 T17585 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-004/]
[junit4] 2> 1456289 T17585 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1456289 T17585 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1456290 T17585 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1456290 T17585 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1456290 T17585 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1456290 T17585 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1456291 T17585 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1456291 T17585 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1456291 T17585 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1456292 T17585 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1456292 T17585 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1456293 T17585 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1456293 T17585 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33211/solr
[junit4] 2> 1456293 T17585 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1456294 T17585 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1456297 T17647 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3fddb051 name:ZooKeeperConnection Watcher:127.0.0.1:33211 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1456297 T17585 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1456300 T17585 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1456301 T17649 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@42f8036e name:ZooKeeperConnection Watcher:127.0.0.1:33211/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1456301 T17585 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1456318 T17585 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1457321 T17585 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33223__yrr%2Fz
[junit4] 2> 1457323 T17585 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:33223__yrr%2Fz
[junit4] 2> 1457326 T17649 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1457326 T17630 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1457326 T17607 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1457326 T17617 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1457335 T17650 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 1457336 T17650 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1457337 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1457337 T17650 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1457337 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1457338 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1457338 T17608 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1457339 T17608 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:33223/_yrr/z",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:33223__yrr%2Fz",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1457339 T17608 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1457340 T17608 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1457349 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1457350 T17649 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1457350 T17617 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1457350 T17630 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1457350 T17607 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1458339 T17650 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1458339 T17650 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1458340 T17650 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1458340 T17650 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1458341 T17650 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1458341 T17650 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-004/collection1/'
[junit4] 2> 1458342 T17650 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-004/collection1/lib/README' to classloader
[junit4] 2> 1458343 T17650 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-004/collection1/lib/classes/' to classloader
[junit4] 2> 1458344 T17650 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-004/collection1/lib/.svn/' to classloader
[junit4] 2> 1458425 T17650 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
[junit4] 2> 1458506 T17650 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1458607 T17650 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1458620 T17650 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1459345 T17650 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1459346 T17650 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1459347 T17650 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1459361 T17650 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1459366 T17650 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1459378 T17650 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1459383 T17650 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1459388 T17650 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1459389 T17650 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1459389 T17650 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1459390 T17650 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1459390 T17650 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1459391 T17650 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1459391 T17650 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 1459391 T17650 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1459392 T17650 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-004/collection1/, dataDir=./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-001/jetty2/
[junit4] 2> 1459392 T17650 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fc2aa1f
[junit4] 2> 1459394 T17650 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-001/jetty2
[junit4] 2> 1459395 T17650 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-001/jetty2/index/
[junit4] 2> 1459395 T17650 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 1459395 T17650 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.HttpPartitionTest-8BD0FFE29E754FA-001/tempDir-001/jetty2/index
[junit4] 2> 1459396 T17650 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=42.9248046875, floorSegmentMB=1.103515625, forceMergeDeletesPctAllowed=19.97506321927009, segmentsPerTier=35.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1459397 T17650 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@f9d6fd0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d100357),segFN=segments_1,generation=1}
[junit4] 2> 1459397 T17650 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1459404 T17650 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1459405 T17650 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1459405 T17650 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1459405 T17650 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1459406 T17650 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1459406 T17650 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1459407 T17650 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1459407 T17650 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1459407 T17650 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1459408 T17650 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1459409 T17650 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1459409 T17650 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1459410 T17650 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1459411 T17650 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1459411 T17650 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1459412 T17650 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1459431 T17650 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1459437 T17650 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1459437 T17650 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1459438 T17650 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=25, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1459439 T17650 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@f9d6fd0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d100357),segFN=segments_1,generation=1}
[junit4] 2> 1459439 T17650 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1459440 T17650 oass.SolrIndexSearcher.<init> Opening Searcher@2983c6e0[collection1] main
[junit4] 2> 1459440 T17650 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1459441 T17650 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1459442 T17650 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 1459442 T17650 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1459442 T17650 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 1459443 T17650 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1459443 T17650 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 1459444 T17650 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1459444 T17650 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 1459444 T17650 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 1459449 T17651 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2983c6e0[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1459453 T17650 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1459454 T17654 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:33223/_yrr/z collection:collection1 shard:shard2
[junit4] 2> 1459454 T17585 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1
[junit4] 2> 1459455 T17654 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1459455 T17585 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1459457 T17585 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1459458 T17585 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 30000 for each attempt
[junit4] 2> 1459459 T17585 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):30000
[junit4] 2> 1459459 T17585 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1459473 T17654 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 1459476 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1459476 T17654 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1459476 T17654 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1213 name=collection1 org.apache.solr.core.SolrCore@5b932814 url=http://127.0.0.1:33223/_yrr/z/collection1 node=127.0.0.1:33223__yrr%2Fz C1213_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:33223/_yrr/z, core=collection1, node_name=127.0.0.1:33223__yrr%2Fz}
[junit4] 2> 1459476 T17654 C1213 P33223 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:33223/_yrr/z/collection1/
[junit4] 2> 1459477 T17608 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1459477 T17654 C1213 P33223 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1459477 T17654 C1213 P33223 oasc.SyncStrategy.syncToMe http://127.0.0.1:33223/_yrr/z/collection1/ has no replicas
[junit4] 2> 1459478 T17654 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:33223/_yrr/z/collection1/ shard2
[junit4] 2> 1459478 T17654 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1459487 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1459488 T17617 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1459488 T17630 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1459488 T17649 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1459488 T17607 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1459491 T17608 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1459493 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1459595 T17617 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1459595 T17630 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1459595 T17649 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1459595 T17607 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1459643 T17654 oasc.ZkController.register We are http://127.0.0.1:33223/_yrr/z/collection1/ and leader is http://127.0.0.1:33223/_yrr/z/collection1/
[junit4] 2> 1459643 T17654 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:33223/_yrr/z
[junit4] 2> 1459643 T17654 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1459643 T17654 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 1459644 T17654 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1459645 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1459645 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1459645 T17654 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1459646 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1459647 T17608 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1459648 T17608 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:33223/_yrr/z",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:33223__yrr%2Fz",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 1459656 T17607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1459758 T17607 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1459758 T17617 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1459758 T17649 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1459758 T17630 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1460474 T17585 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1460475 T17585 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4] 2> 1460477 T17615 oasc.SocketProxy$Acceptor.run accepted Socket[addr=/140.211.11.196,port=33227,localport=33214], receiveBufferSize:6565888
[junit4] 2> 1460480 T17615 oasc.SocketProxy$Bridge.<init> proxy connection Socket[addr=/127.0.0.1,port=33215,localport=33228], receiveBufferSize=6565888
[junit4] 2> ASYNC NEW_CORE C1214 name=collection1 org.apache.solr.core.SolrCore@4b5d4bf0 url=http://127.0.0.1:33214/_yrr/z/collection1 node=127.0.0.1:33214__yrr%2Fz C1214_STATE=coll:control_collection core:collection1 props:{state=active, base_url=http://127.0.0.1:33214/_yrr/z, core=collection1, node_name=127.0.0.1:33214__yrr%2Fz, leader=true}
[junit4] 2> 1460481 T17597 C1214 P33214 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1460482 T17597 C1214 P33214 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1460483 T17597 C1214 P33214 oasc.SolrCore.openNewSearcher SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
[junit4] 2> 1460484 T17597 C1214 P33214 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 1460484 T17597 C1214 P33214 oasup.LogUpdateProcessor.finish [collection1] webapp=/_yrr/z path=/update params={waitSearcher=true&softCommit=false&version=2&wt=javabin&commit=true} {commit=} 0 3
[junit4] 2> 1460486 T17655 oasc.SocketProxy$Acceptor.run accepted Socket[addr=/140.211.11.196,port=33229,localport=33223], receiveBufferSize:6565888
[junit4] 2> 1460487 T17655 oasc.SocketProxy$Bridge.<init> proxy connection Socket[addr=/127.0.0.1,port=33224,localport=33230], receiveBufferSize=6565888
[junit4] 2> 1460489 T17636 oasc.SocketProxy$Acceptor.run accepted Socket[addr=/140.211.11.196,port=33231,localport=33219], receiveBufferSize:6565888
[junit4] 2> 1460490 T17636 oasc.SocketProxy$Bridge.<init> proxy connection Socket[addr=/127.0.0.1,port=33220,localport=33232], receiveBufferSize=6565888
[junit4] 2> ASYNC NEW_CORE C1215 name=collection1 org.apache.solr.core.SolrCore@304c3211 url=http://127.0.0.1:33219/_yrr/z/collection1 node=127.0.0.1:33219__yrr%2Fz C1215_STATE=coll:collection1 core:collection1 props:{state=active, base_url=http://127.0.0.1:33219/_yrr/z, core=collection1, node_name=127.0.0.1:33219__yrr%2Fz, leader=true}
[junit4] 2> 1460490 T17620 C1215 P33219 oasu.DirectUpdateHandler2.commit start commit{,optimize=fa
[...truncated too long message...]
thread-1, state=WAITING, group=TGRP-CollectionsAPIDistributedZkTest]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
[junit4] 2> at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4] 2> 8) Thread[id=18316, name=HashSessionScavenger-172, state=TIMED_WAITING, group=TGRP-CollectionsAPIDistributedZkTest]
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:552)
[junit4] 2> at java.util.TimerThread.run(Timer.java:505)
[junit4] 2> 9) Thread[id=18486, name=searcherExecutor-2197-thread-1, state=WAITING, group=TGRP-CollectionsAPIDistributedZkTest]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
[junit4] 2> at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4] 2> 10) Thread[id=18575, name=RecoveryThread, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]
[junit4] 2> at java.net.SocketInputStream.socketRead0(Native Method)
[junit4] 2> at java.net.SocketInputStream.read(SocketInputStream.java:150)
[junit4] 2> at java.net.SocketInputStream.read(SocketInputStream.java:121)
[junit4] 2> at sun.security.ssl.InputRecord.readFully(InputRecord.java:442)
[junit4] 2> at sun.security.ssl.InputRecord.read(InputRecord.java:480)
[junit4] 2> at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:927)
[junit4] 2> at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:884)
[junit4] 2> at sun.security.ssl.AppInputStream.read(AppInputStream.java:102)
[junit4] 2> at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160)
[junit4] 2> at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84)
[junit4] 2> at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273)
[junit4] 2> at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
[junit4] 2> at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
[junit4] 2> at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:260)
[junit4] 2> at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283)
[junit4] 2> at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251)
[junit4] 2> at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197)
[junit4] 2> at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:271)
[junit4] 2> at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:123)
[junit4] 2> at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:682)
[junit4] 2> at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:486)
[junit4] 2> at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:863)
[junit4] 2> at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
[junit4] 2> at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106)
[junit4] 2> at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:452)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
[junit4] 2> at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:124)
[junit4] 2> at org.apache.solr.cloud.RecoveryStrategy.commitOnLeader(RecoveryStrategy.java:210)
[junit4] 2> at org.apache.solr.cloud.RecoveryStrategy.replicate(RecoveryStrategy.java:145)
[junit4] 2> at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:447)
[junit4] 2> at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:235)
[junit4] 2> NOTE: test params are: codec=Lucene42, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=en_US, timezone=Asia/Dhaka
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=12,free=313220776,total=483393536
[junit4] 2> NOTE: All tests run in this JVM: [EchoParamsTest, TestBM25SimilarityFactory, TestLuceneMatchVersion, TestSchemaResource, DebugComponentTest, TestComplexPhraseQParserPlugin, SyncSliceTest, HdfsBasicDistributedZk2Test, RankQueryTest, TestFaceting, UnloadDistributedZkTest, HighlighterTest, SynonymTokenizerTest, DocumentBuilderTest, TestFiltering, TestCSVResponseWriter, HdfsSyncSliceTest, TestSystemIdResolver, TermVectorComponentTest, StatelessScriptUpdateProcessorFactoryTest, TestCharFilters, TestUniqueKeyFieldResource, ScriptEngineTest, TestStressRecovery, TestCursorMarkWithoutUniqueKey, TestSweetSpotSimilarityFactory, TestSolrCoreProperties, TestOmitPositions, TestAtomicUpdateErrorCases, TestSolrQueryParser, TestSolrXmlPersistence, StandardRequestHandlerTest, TestManagedSchemaFieldResource, CursorMarkTest, DirectSolrConnectionTest, TestCodecSupport, BadCopyFieldTest, TestWriterPerf, URLClassifyProcessorTest, TestStressReorder, ClusterStateTest, TermVectorComponentDistributedTest, TestRangeQuery, TestFieldTypeResource, ChaosMonkeySafeLeaderTest, TestReplicationHandler, TimeZoneUtilsTest, AlternateDirectoryTest, AddBlockUpdateTest, MergeStrategyTest, ZkCLITest, TriLevelCompositeIdRoutingTest, BasicZkTest, TestSearchPerf, DocValuesMultiTest, DOMUtilTest, SpellCheckCollatorTest, ResourceLoaderTest, ConnectionManagerTest, TestJmxMonitoredMap, OverseerTest, AliasIntegrationTest, TestWordDelimiterFilterFactory, DistribCursorPagingTest, TestSolrXMLSerializer, ShardRoutingTest, HttpPartitionTest, TestFieldResource, TestMultiCoreConfBootstrap, DistributedQueryComponentCustomSortTest, TestDocumentBuilder, ChaosMonkeyNothingIsSafeTest, MoreLikeThisHandlerTest, CollectionsAPIDistributedZkTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.seed=8BD0FFE29E754FA -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=en_US -Dtests.timezone=Asia/Dhaka -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 0.00s J1 | CollectionsAPIDistributedZkTest (suite) <<<
[junit4] > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
[junit4] > at __randomizedtesting.SeedInfo.seed([8BD0FFE29E754FA]:0)
[junit4] Completed on J1 in 7223.48s, 1 test, 2 errors <<< FAILURES!
[...truncated 83 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:467: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:447: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:45: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/common-build.xml:496: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:1297: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:921: There were test failures: 396 suites, 1640 tests, 1 suite-level error, 2 errors, 157 ignored (15 assumptions)
Total time: 198 minutes 28 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure