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 2013/12/04 11:22:20 UTC
[JENKINS] Lucene-Solr-Tests-4.x-Java7 - Build # 1798 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java7/1798/
1 tests failed.
REGRESSION: org.apache.solr.cloud.ShardSplitTest.testDistribSearch
Error Message:
Wrong doc count on shard1_0 expected:<264> but was:<216>
Stack Trace:
java.lang.AssertionError: Wrong doc count on shard1_0 expected:<264> but was:<216>
at __randomizedtesting.SeedInfo.seed([C73052A34E85B8EA:46D6DCBB39DAD8D6]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:477)
at org.apache.solr.cloud.ShardSplitTest.splitByUniqueKeyTest(ShardSplitTest.java:249)
at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:113)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:843)
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:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 10533 lines...]
[junit4] Suite: org.apache.solr.cloud.ShardSplitTest
[junit4] 2> 1105886 T1961 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /tlrl/xq
[junit4] 2> 1105893 T1961 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1386150644364
[junit4] 2> 1105895 T1961 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1105896 T1962 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1105997 T1961 oasc.ZkTestServer.run start zk server on port:23907
[junit4] 2> 1105998 T1961 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1106002 T1968 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@257f3620 name:ZooKeeperConnection Watcher:127.0.0.1:23907 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1106003 T1961 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1106003 T1961 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1106015 T1961 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1106017 T1970 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c28762e name:ZooKeeperConnection Watcher:127.0.0.1:23907/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1106018 T1961 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1106018 T1961 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1106027 T1961 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1106030 T1961 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1106038 T1961 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1106041 T1961 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1106042 T1961 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1106055 T1961 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 1106056 T1961 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1106160 T1961 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1106161 T1961 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1106165 T1961 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1106166 T1961 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1106173 T1961 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1106174 T1961 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1106178 T1961 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1106178 T1961 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1106182 T1961 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 1106183 T1961 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 1106186 T1961 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1106187 T1961 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1106190 T1961 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1106191 T1961 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1106194 T1961 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1106195 T1961 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1106199 T1961 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1106199 T1961 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1106536 T1961 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1106541 T1961 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:23910
[junit4] 2> 1106542 T1961 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1106542 T1961 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1106543 T1961 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-controljetty-1386150644673
[junit4] 2> 1106543 T1961 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-controljetty-1386150644673/'
[junit4] 2> 1106590 T1961 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1386150644673/solr.xml
[junit4] 2> 1106698 T1961 oasc.CoreContainer.<init> New CoreContainer 496770932
[junit4] 2> 1106699 T1961 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-controljetty-1386150644673/]
[junit4] 2> 1106701 T1961 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1106701 T1961 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1106702 T1961 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1106702 T1961 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1106703 T1961 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1106703 T1961 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1106704 T1961 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1106704 T1961 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1106705 T1961 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1106727 T1961 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1106728 T1961 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1106729 T1961 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1106729 T1961 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:23907/solr
[junit4] 2> 1106730 T1961 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1106731 T1961 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1106734 T1981 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f5176f name:ZooKeeperConnection Watcher:127.0.0.1:23907 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1106734 T1961 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1106737 T1961 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1106746 T1983 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ca1d676 name:ZooKeeperConnection Watcher:127.0.0.1:23907/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1106747 T1961 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1106749 T1961 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1106759 T1961 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1106763 T1961 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1106765 T1961 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:23910_tlrl%2Fxq
[junit4] 2> 1106767 T1961 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:23910_tlrl%2Fxq
[junit4] 2> 1106776 T1961 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1106791 T1961 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1106798 T1961 oasc.Overseer.start Overseer (id=90842768629694467-127.0.0.1:23910_tlrl%2Fxq-n_0000000000) starting
[junit4] 2> 1106803 T1961 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1106817 T1985 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1106818 T1961 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1106821 T1961 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1106823 T1961 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1106826 T1984 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1106832 T1986 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1106832 T1986 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1106834 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1106834 T1986 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1106835 T1984 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1106836 T1984 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:23910/tlrl/xq",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:23910_tlrl%2Fxq",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1106836 T1984 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 1106837 T1984 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1106840 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1106848 T1983 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> 1107835 T1986 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1107835 T1986 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-controljetty-1386150644673/collection1
[junit4] 2> 1107835 T1986 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1107836 T1986 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1107836 T1986 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1107837 T1986 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-controljetty-1386150644673/collection1/'
[junit4] 2> 1107838 T1986 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1386150644673/collection1/lib/README' to classloader
[junit4] 2> 1107839 T1986 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1386150644673/collection1/lib/classes/' to classloader
[junit4] 2> 1107891 T1986 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 1107942 T1986 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1108043 T1986 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1108051 T1986 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1108514 T1986 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1108517 T1986 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1108519 T1986 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1108523 T1986 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1108545 T1986 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1108545 T1986 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-controljetty-1386150644673/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1386150644363/control/data/
[junit4] 2> 1108545 T1986 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@30f8e65a
[junit4] 2> 1108546 T1986 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1386150644363/control/data
[junit4] 2> 1108546 T1986 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1386150644363/control/data/index/
[junit4] 2> 1108546 T1986 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1386150644363/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1108547 T1986 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1386150644363/control/data/index
[junit4] 2> 1108547 T1986 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=43, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1108548 T1986 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2f336ad4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f924913),segFN=segments_1,generation=1}
[junit4] 2> 1108548 T1986 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1108551 T1986 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1108552 T1986 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1108552 T1986 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1108552 T1986 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1108552 T1986 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1108553 T1986 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1108553 T1986 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1108553 T1986 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1108554 T1986 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1108554 T1986 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1108555 T1986 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1108555 T1986 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1108555 T1986 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1108555 T1986 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1108556 T1986 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1108556 T1986 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1108570 T1986 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1108575 T1986 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1108575 T1986 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1108575 T1986 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=40, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1108576 T1986 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2f336ad4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f924913),segFN=segments_1,generation=1}
[junit4] 2> 1108576 T1986 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1108577 T1986 oass.SolrIndexSearcher.<init> Opening Searcher@41e643c3 main
[junit4] 2> 1108579 T1987 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@41e643c3 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1108580 T1986 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1108581 T1986 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:23910/tlrl/xq collection:control_collection shard:shard1
[junit4] 2> 1108581 T1986 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1108605 T1986 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1108607 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1108608 T1986 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1108608 T1986 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C439 name=collection1 org.apache.solr.core.SolrCore@3c0c7b71 url=http://127.0.0.1:23910/tlrl/xq/collection1 node=127.0.0.1:23910_tlrl%2Fxq C439_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:23910/tlrl/xq, core=collection1, node_name=127.0.0.1:23910_tlrl%2Fxq}
[junit4] 2> 1108608 T1986 C439 P23910 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:23910/tlrl/xq/collection1/
[junit4] 2> 1108608 T1986 C439 P23910 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1108608 T1984 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1108608 T1986 C439 P23910 oasc.SyncStrategy.syncToMe http://127.0.0.1:23910/tlrl/xq/collection1/ has no replicas
[junit4] 2> 1108609 T1986 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:23910/tlrl/xq/collection1/ shard1
[junit4] 2> 1108609 T1986 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1108611 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1108612 T1983 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> 1108616 T1984 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1108619 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1108721 T1983 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> 1108768 T1986 oasc.ZkController.register We are http://127.0.0.1:23910/tlrl/xq/collection1/ and leader is http://127.0.0.1:23910/tlrl/xq/collection1/
[junit4] 2> 1108768 T1986 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:23910/tlrl/xq
[junit4] 2> 1108768 T1986 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1108768 T1986 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1108769 T1986 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1108770 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1108770 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1108770 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1108770 T1986 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1108771 T1961 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1108772 T1961 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1108771 T1984 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1108773 T1984 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:23910/tlrl/xq",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:23910_tlrl%2Fxq",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1108774 T1961 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1108782 T1990 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7a131799 name:ZooKeeperConnection Watcher:127.0.0.1:23907/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1108783 T1961 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1108790 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1108790 T1961 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1108792 T1961 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 1108893 T1983 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> 1108893 T1990 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> 1109051 T1961 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1109054 T1961 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:23914
[junit4] 2> 1109054 T1961 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1109055 T1961 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1109055 T1961 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1386150647262
[junit4] 2> 1109055 T1961 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1386150647262/'
[junit4] 2> 1109092 T1961 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1386150647262/solr.xml
[junit4] 2> 1109169 T1961 oasc.CoreContainer.<init> New CoreContainer 762160343
[junit4] 2> 1109170 T1961 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1386150647262/]
[junit4] 2> 1109171 T1961 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1109172 T1961 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1109172 T1961 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1109172 T1961 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1109173 T1961 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1109173 T1961 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1109173 T1961 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1109174 T1961 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1109174 T1961 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1109187 T1961 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1109188 T1961 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1109188 T1961 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1109189 T1961 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:23907/solr
[junit4] 2> 1109189 T1961 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1109190 T1961 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1109218 T2001 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@33de4ada name:ZooKeeperConnection Watcher:127.0.0.1:23907 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1109218 T1961 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1109221 T1961 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1109229 T2003 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d2b0bb7 name:ZooKeeperConnection Watcher:127.0.0.1:23907/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1109229 T1961 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1109233 T1961 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1110236 T1961 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:23914_tlrl%2Fxq
[junit4] 2> 1110238 T1961 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:23914_tlrl%2Fxq
[junit4] 2> 1110242 T1990 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1110242 T1983 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1110242 T2003 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1110249 T2004 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1110250 T2004 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1110251 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1110251 T2004 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1110251 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1110252 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1110253 T1984 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1110254 T1984 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:23914/tlrl/xq",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:23914_tlrl%2Fxq",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1110254 T1984 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 1110254 T1984 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1110268 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1110371 T1983 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> 1110371 T1990 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> 1110371 T2003 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> 1111253 T2004 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1111253 T2004 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1386150647262/collection1
[junit4] 2> 1111254 T2004 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1111255 T2004 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1111255 T2004 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1111256 T2004 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1386150647262/collection1/'
[junit4] 2> 1111258 T2004 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1386150647262/collection1/lib/README' to classloader
[junit4] 2> 1111259 T2004 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1386150647262/collection1/lib/classes/' to classloader
[junit4] 2> 1111328 T2004 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 1111396 T2004 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1111497 T2004 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1111509 T2004 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1112083 T2004 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1112087 T2004 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1112090 T2004 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1112095 T2004 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1112120 T2004 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1112121 T2004 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1386150647262/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1386150644363/jetty1/
[junit4] 2> 1112121 T2004 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@30f8e65a
[junit4] 2> 1112122 T2004 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1386150644363/jetty1
[junit4] 2> 1112122 T2004 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1386150644363/jetty1/index/
[junit4] 2> 1112122 T2004 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1386150644363/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 1112122 T2004 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1386150644363/jetty1/index
[junit4] 2> 1112123 T2004 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=43, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1112124 T2004 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@548cff52 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6a9097c1),segFN=segments_1,generation=1}
[junit4] 2> 1112124 T2004 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1112154 T2004 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1112154 T2004 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1112155 T2004 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1112155 T2004 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1112156 T2004 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1112156 T2004 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1112157 T2004 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1112157 T2004 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1112157 T2004 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1112158 T2004 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1112159 T2004 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1112159 T2004 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1112160 T2004 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1112161 T2004 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1112161 T2004 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1112162 T2004 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1112181 T2004 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1112188 T2004 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1112188 T2004 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1112189 T2004 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=40, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1112190 T2004 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@548cff52 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6a9097c1),segFN=segments_1,generation=1}
[junit4] 2> 1112190 T2004 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1112190 T2004 oass.SolrIndexSearcher.<init> Opening Searcher@52dcb88a main
[junit4] 2> 1112195 T2005 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@52dcb88a main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1112198 T2004 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1112198 T2004 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:23914/tlrl/xq collection:collection1 shard:shard2
[junit4] 2> 1112199 T2004 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1112233 T2004 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 1112244 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1112244 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1112244 T2004 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1112244 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1112245 T2004 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1112245 T1984 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> ASYNC NEW_CORE C440 name=collection1 org.apache.solr.core.SolrCore@13534a5d url=http://127.0.0.1:23914/tlrl/xq/collection1 node=127.0.0.1:23914_tlrl%2Fxq C440_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:23914/tlrl/xq, core=collection1, node_name=127.0.0.1:23914_tlrl%2Fxq}
[junit4] 2> 1112245 T2004 C440 P23914 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:23914/tlrl/xq/collection1/
[junit4] 2> 1112246 T2004 C440 P23914 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1112246 T2004 C440 P23914 oasc.SyncStrategy.syncToMe http://127.0.0.1:23914/tlrl/xq/collection1/ has no replicas
[junit4] 2> 1112247 T2004 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:23914/tlrl/xq/collection1/ shard2
[junit4] 2> 1112247 T2004 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1112249 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1112259 T2003 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> 1112260 T1990 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> 1112260 T1983 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> 1112271 T1984 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1112275 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1112378 T1983 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> 1112378 T1990 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> 1112381 T2003 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> 1112424 T2004 oasc.ZkController.register We are http://127.0.0.1:23914/tlrl/xq/collection1/ and leader is http://127.0.0.1:23914/tlrl/xq/collection1/
[junit4] 2> 1112424 T2004 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:23914/tlrl/xq
[junit4] 2> 1112424 T2004 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1112425 T2004 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1112425 T2004 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1112426 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1112427 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1112427 T2004 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1112427 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1112428 T1961 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1112429 T1961 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1112429 T1984 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1112430 T1984 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:23914/tlrl/xq",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:23914_tlrl%2Fxq",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1112433 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1112536 T1983 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> 1112536 T2003 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> 1112536 T1990 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> 1112768 T1961 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1112771 T1961 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:23917
[junit4] 2> 1112772 T1961 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1112773 T1961 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1112773 T1961 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-jetty2-1386150650899
[junit4] 2> 1112774 T1961 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty2-1386150650899/'
[junit4] 2> 1112821 T1961 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1386150650899/solr.xml
[junit4] 2> 1112923 T1961 oasc.CoreContainer.<init> New CoreContainer 1108305777
[junit4] 2> 1112924 T1961 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-jetty2-1386150650899/]
[junit4] 2> 1112926 T1961 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1112926 T1961 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1112927 T1961 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1112927 T1961 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1112928 T1961 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1112928 T1961 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1112929 T1961 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1112929 T1961 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1112929 T1961 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1112948 T1961 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1112948 T1961 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1112949 T1961 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1112949 T1961 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:23907/solr
[junit4] 2> 1112950 T1961 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1112951 T1961 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1112953 T2017 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29725f1 name:ZooKeeperConnection Watcher:127.0.0.1:23907 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1112954 T1961 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1112957 T1961 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1112964 T2019 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7bde0481 name:ZooKeeperConnection Watcher:127.0.0.1:23907/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1112964 T1961 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1112969 T1961 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1113973 T1961 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:23917_tlrl%2Fxq
[junit4] 2> 1113976 T1961 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:23917_tlrl%2Fxq
[junit4] 2> 1113980 T2003 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1113980 T1983 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1113980 T1990 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1113980 T2019 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1114001 T2020 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1114001 T2020 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1114003 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1114003 T2020 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1114003 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1114004 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1114005 T1984 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1114006 T1984 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:23917/tlrl/xq",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:23917_tlrl%2Fxq",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1114006 T1984 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1114007 T1984 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1114009 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1114113 T1990 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> 1114113 T2003 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> 1114113 T2019 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> 1114113 T1983 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> 1115004 T2020 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1115004 T2020 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-jetty2-1386150650899/collection1
[junit4] 2> 1115005 T2020 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1115006 T2020 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1115006 T2020 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1115007 T2020 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty2-1386150650899/collection1/'
[junit4] 2> 1115009 T2020 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1386150650899/collection1/lib/README' to classloader
[junit4] 2> 1115009 T2020 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1386150650899/collection1/lib/classes/' to classloader
[junit4] 2> 1115083 T2020 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 1115156 T2020 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1115257 T2020 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1115269 T2020 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1115906 T2020 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1115911 T2020 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1115914 T2020 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1115920 T2020 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1115948 T2020 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1115948 T2020 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-jetty2-1386150650899/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1386150644363/jetty2/
[junit4] 2> 1115949 T2020 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@30f8e65a
[junit4] 2> 1115950 T2020 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1386150644363/jetty2
[junit4] 2> 1115950 T2020 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1386150644363/jetty2/index/
[junit4] 2> 1115950 T2020 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1386150644363/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 1115951 T2020 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1386150644363/jetty2/index
[junit4] 2> 1115951 T2020 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=43, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1115952 T2020 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@55bd10d2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3b772eb5),segFN=segments_1,generation=1}
[junit4] 2> 1115953 T2020 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1115958 T2020 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1115959 T2020 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1115959 T2020 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1115960 T2020 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1115960 T2020 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1115960 T2020 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1115961 T2020 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1115962 T2020 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1115962 T2020 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1115963 T2020 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1115964 T2020 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1115964 T2020 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1115964 T2020 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1115965 T2020 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1115966 T2020 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1115966 T2020 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1115986 T2020 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1115992 T2020 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1115992 T2020 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1115993 T2020 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=40, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1115994 T2020 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@55bd10d2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3b772eb5),segFN=segments_1,generation=1}
[junit4] 2> 1115994 T2020 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1115994 T2020 oass.SolrIndexSearcher.<init> Opening Searcher@4a9368e8 main
[junit4] 2> 1115999 T2021 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4a9368e8 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1116002 T2020 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1116002 T2020 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:23917/tlrl/xq collection:collection1 shard:shard1
[junit4] 2> 1116004 T2020 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1116046 T2020 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1116049 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116050 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116050 T2020 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1116050 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116050 T2020 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C441 name=collection1 org.apache.solr.core.SolrCore@3564d8c2 url=http://127.0.0.1:23917/tlrl/xq/collection1 node=127.0.0.1:23917_tlrl%2Fxq C441_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:23917/tlrl/xq, core=collection1, node_name=127.0.0.1:23917_tlrl%2Fxq}
[junit4] 2> 1116051 T2020 C441 P23917 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:23917/tlrl/xq/collection1/
[junit4] 2> 1116051 T2020 C441 P23917 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1116051 T2020 C441 P23917 oasc.SyncStrategy.syncToMe http://127.0.0.1:23917/tlrl/xq/collection1/ has no replicas
[junit4] 2> 1116052 T2020 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:23917/tlrl/xq/collection1/ shard1
[junit4] 2> 1116052 T1984 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1116052 T2020 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1116056 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116065 T1983 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> 1116065 T2003 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> 1116065 T1990 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> 1116065 T2019 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> 1116076 T1984 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1116086 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116189 T2019 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> 1116189 T1990 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> 1116189 T2003 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> 1116189 T1983 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> 1116227 T2020 oasc.ZkController.register We are http://127.0.0.1:23917/tlrl/xq/collection1/ and leader is http://127.0.0.1:23917/tlrl/xq/collection1/
[junit4] 2> 1116227 T2020 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:23917/tlrl/xq
[junit4] 2> 1116228 T2020 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1116228 T2020 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1116228 T2020 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1116230 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116230 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116230 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116230 T2020 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1116232 T1961 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
[junit4] 2> 1116232 T1961 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1116232 T1984 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1116234 T1984 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:23917/tlrl/xq",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:23917_tlrl%2Fxq",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 1116237 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116341 T1983 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> 1116341 T2003 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> 1116341 T1990 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> 1116341 T2019 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> 1116544 T1961 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1116548 T1961 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:23920
[junit4] 2> 1116549 T1961 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1116549 T1961 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1116550 T1961 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-jetty3-1386150654703
[junit4] 2> 1116550 T1961 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty3-1386150654703/'
[junit4] 2> 1116595 T1961 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1386150654703/solr.xml
[junit4] 2> 1116670 T1961 oasc.CoreContainer.<init> New CoreContainer 440645185
[junit4] 2> 1116670 T1961 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-jetty3-1386150654703/]
[junit4] 2> 1116672 T1961 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1116672 T1961 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1116672 T1961 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1116673 T1961 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1116673 T1961 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1116673 T1961 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1116674 T1961 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1116674 T1961 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1116674 T1961 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1116687 T1961 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1116688 T1961 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1116688 T1961 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1116688 T1961 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:23907/solr
[junit4] 2> 1116689 T1961 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1116690 T1961 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1116693 T2033 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@721a3067 name:ZooKeeperConnection Watcher:127.0.0.1:23907 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1116693 T1961 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1116705 T1961 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1116707 T2035 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@844b95f name:ZooKeeperConnection Watcher:127.0.0.1:23907/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1116707 T1961 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1116717 T1961 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1117721 T1961 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:23920_tlrl%2Fxq
[junit4] 2> 1117733 T1961 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:23920_tlrl%2Fxq
[junit4] 2> 1117746 T2035 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1117746 T2019 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1117746 T2003 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1117746 T1983 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1117746 T1990 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1117758 T2036 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1117758 T2036 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1117760 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1117760 T2036 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1117761 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1117761 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1117762 T1984 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1117763 T1984 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:23920/tlrl/xq",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:23920_tlrl%2Fxq",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1117763 T1984 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1117763 T1984 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1117775 T1983 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1117878 T2003 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1117878 T1983 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1117878 T2035 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1117878 T1990 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1117878 T2019 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1118762 T2036 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1118762 T2036 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-jetty3-1386150654703/collection1
[junit4] 2> 1118762 T2036 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1118763 T2036 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1118764 T2036 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1118765 T2036 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty3-1386150654703/collection1/'
[junit4] 2> 1118766 T2036 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1386150654703/collection1/lib/README' to classloader
[junit4] 2> 1118767 T2036 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1386150654703/collection1/lib/classes/' to classloader
[junit4] 2> 1118861 T2036 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 1118907 T2036 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1119009 T2036 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1119017 T2036 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1119430 T2036 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1119433 T2036 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1119435 T2036 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1119440 T2036 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1119464 T2036 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1119464 T2036 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-jetty3-1386150654703/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1386150644363/jetty3/
[junit4] 2> 1119465 T2036 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@30f8e65a
[junit4] 2> 1119467 T2036 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1386150644363/jetty3
[junit4] 2> 1119467 T2036 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1386150644363/jetty3/index/
[junit4] 2> 1119467 T2036 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1386150644363/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 1119467 T2036 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1386150644363/jetty3/index
[junit4] 2> 1119468 T2036 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=43, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1119468 T2036 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7d8e213 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@203f5255),segFN=segments_1,generation=1}
[junit4] 2> 1119469 T2036 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1119472 T2036 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1119473 T2036 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1119473 T2036 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1119473 T2036 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1119474 T2036 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1119474 T2036 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 11
[...truncated too long message...]
o close ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1386150657982/collection1_shard1_1_replica2/data/index [CachedDir<<refCount=0;path=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1386150657982/collection1_shard1_1_replica2/data/index;done=false>>]
[junit4] 2> 1302531 T1961 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1386150657982/collection1_shard1_1_replica2/data/index
[junit4] 2> 1302531 T1961 oasc.CachingDirectoryFactory.closeCacheValue looking to close ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1386150657982/collection1_shard1_1_replica2/data [CachedDir<<refCount=0;path=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1386150657982/collection1_shard1_1_replica2/data;done=false>>]
[junit4] 2> 1302532 T1961 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1386150657982/collection1_shard1_1_replica2/data
[junit4] 2> 1302535 T1961 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/tlrl/xq,null}
[junit4] 2> 1302535 T2097 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1302603 T1961 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 1302604 T1961 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:23907 23907
[junit4] 2> 1302814 T2097 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3731777e name:ZooKeeperConnection Watcher:127.0.0.1:23907/solr got event WatchedEvent state:Disconnected type:None path:null path:null type:None
[junit4] 2> 1302814 T2097 oascc.ConnectionManager.process Client->ZooKeeper status change trigger but we are already closed
[junit4] 2> 1302814 T1961 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 23910
[junit4] 2> !!!! WARNING: best effort to remove /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-1386150644363 FAILED !!!!!
[junit4] 2> 1302815 T1961 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 1302816 T1961 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:23907 23907
[junit4] 1> "base_url":"http://127.0.0.1:23917/tlrl/xq",
[junit4] 1> "node_name":"127.0.0.1:23917_tlrl%2Fxq"}
[junit4] 1> /solr/collections/collection1/leaders/shard2 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1",
[junit4] 1> "base_url":"http://127.0.0.1:23914/tlrl/xq",
[junit4] 1> "node_name":"127.0.0.1:23914_tlrl%2Fxq"}
[junit4] 1> /solr/collections/collection1/leaders/shard1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1",
[junit4] 1> "base_url":"http://127.0.0.1:23917/tlrl/xq",
[junit4] 1> "node_name":"127.0.0.1:23917_tlrl%2Fxq"}
[junit4] 1> /solr/collections/collection1/leaders/shard1_1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1_shard1_1_replica1",
[junit4] 1> "base_url":"http://127.0.0.1:23917/tlrl/xq",
[junit4] 1> "node_name":"127.0.0.1:23917_tlrl%2Fxq"}
[junit4] 1> /solr/overseer_elect (2)
[junit4] 1> /solr/overseer_elect/election (5)
[junit4] 1> /solr/overseer_elect/election/90842768629694476-127.0.0.1:23924_tlrl%2Fxq-n_0000000004 (0)
[junit4] 1> /solr/overseer_elect/election/90842768629694474-127.0.0.1:23920_tlrl%2Fxq-n_0000000003 (0)
[junit4] 1> /solr/overseer_elect/election/90842768629694470-127.0.0.1:23914_tlrl%2Fxq-n_0000000001 (0)
[junit4] 1> /solr/overseer_elect/election/90842768629694467-127.0.0.1:23910_tlrl%2Fxq-n_0000000000 (0)
[junit4] 1> /solr/overseer_elect/election/90842768629694472-127.0.0.1:23917_tlrl%2Fxq-n_0000000002 (0)
[junit4] 1> /solr/overseer_elect/leader (0)
[junit4] 1> DATA:
[junit4] 1> {"id":"90842768629694467-127.0.0.1:23910_tlrl%2Fxq-n_0000000000"}
[junit4] 1> /zookeeper (1)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ShardSplitTest -Dtests.method=testDistribSearch -Dtests.seed=C73052A34E85B8EA -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ko -Dtests.timezone=Asia/Pyongyang -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 197s J0 | ShardSplitTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: Wrong doc count on shard1_0 expected:<264> but was:<216>
[junit4] > at __randomizedtesting.SeedInfo.seed([C73052A34E85B8EA:46D6DCBB39DAD8D6]:0)
[junit4] > at org.apache.solr.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:477)
[junit4] > at org.apache.solr.cloud.ShardSplitTest.splitByUniqueKeyTest(ShardSplitTest.java:249)
[junit4] > at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:113)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:843)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] 2> 1302841 T1961 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 196961 T1960 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4] 2> 1304035 T2052 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Appending, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=ko, timezone=Asia/Pyongyang
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=184293272,total=469762048
[junit4] 2> NOTE: All tests run in this JVM: [TestDefaultSearchFieldResource, IndexSchemaTest, QueryResultKeyTest, ZkCLITest, TestValueSourceCache, DOMUtilTest, TestSolrXmlPersistor, CSVRequestHandlerTest, HighlighterTest, TestFieldTypeResource, TestBinaryField, TestUpdate, TestSuggestSpellingConverter, TestWriterPerf, DeleteInactiveReplicaTest, TestCoreDiscovery, SolrCoreTest, SuggesterTSTTest, MigrateRouteKeyTest, TestRecovery, SolrCoreCheckLockOnStartupTest, TestMultiCoreConfBootstrap, TestNumberUtils, TestSweetSpotSimilarityFactory, MultiTermTest, TestDocSet, TestBinaryResponseWriter, TestCollapseQParserPlugin, SolrCmdDistributorTest, TestStressVersions, TestSearchPerf, TestSchemaSimilarityResource, FieldAnalysisRequestHandlerTest, TestCollationField, OutputWriterTest, TestLFUCache, DateFieldTest, BinaryUpdateRequestHandlerTest, SimpleFacetsTest, InfoHandlerTest, TestDistributedSearch, ZkNodePropsTest, TestManagedSchema, CopyFieldTest, TestCharFilters, DefaultValueUpdateProcessorTest, DocValuesMultiTest, TestCloudManagedSchema, SuggesterFSTTest, TestOmitPositions, TestFastOutputStream, CircularListTest, AlternateDirectoryTest, TestRandomFaceting, PreAnalyzedUpdateProcessorTest, TestFieldCollectionResource, ClusterStateUpdateTest, TestCoreContainer, CurrencyFieldXmlFileTest, UnloadDistributedZkTest, AddBlockUpdateTest, BasicFunctionalityTest, TestSolrXmlPersistence, TestReloadAndDeleteDocs, DocumentBuilderTest, HdfsSyncSliceTest, SystemInfoHandlerTest, TestSerializedLuceneMatchVersion, AliasIntegrationTest, ZkSolrClientTest, SampleTest, BadCopyFieldTest, TestPostingsSolrHighlighter, BasicZkTest, TestHighFrequencyDictionaryFactory, EnumFieldTest, HardAutoCommitTest, TestArbitraryIndexDir, TestDynamicFieldCollectionResource, CacheHeaderTest, XsltUpdateRequestHandlerTest, ShardSplitTest]
[junit4] Completed on J0 in 198.26s, 1 test, 1 failure <<< FAILURES!
[...truncated 562 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:426: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:406: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:39: 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:491: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:1307: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:940: There were test failures: 347 suites, 1516 tests, 1 failure, 34 ignored (6 assumptions)
Total time: 77 minutes 34 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 # 1799 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java7/1799/
1 tests failed.
FAILED: org.apache.solr.cloud.ShardSplitTest.testDistribSearch
Error Message:
Wrong doc count on shard1_0 expected:<269> but was:<195>
Stack Trace:
java.lang.AssertionError: Wrong doc count on shard1_0 expected:<269> but was:<195>
at __randomizedtesting.SeedInfo.seed([347428AAA79D707F:B592A6B2D0C21043]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:477)
at org.apache.solr.cloud.ShardSplitTest.splitByUniqueKeyTest(ShardSplitTest.java:249)
at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:113)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:843)
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:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 10283 lines...]
[junit4] Suite: org.apache.solr.cloud.ShardSplitTest
[junit4] 2> 783828 T1611 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 783835 T1611 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./solrtest-ShardSplitTest-1386191925817
[junit4] 2> 783837 T1611 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 783837 T1612 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 783938 T1611 oasc.ZkTestServer.run start zk server on port:47057
[junit4] 2> 783939 T1611 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 783943 T1618 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3d472d6a name:ZooKeeperConnection Watcher:127.0.0.1:47057 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 783944 T1611 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 783944 T1611 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 783964 T1611 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 783966 T1620 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6dad32a0 name:ZooKeeperConnection Watcher:127.0.0.1:47057/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 783967 T1611 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 783967 T1611 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 783971 T1611 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 783974 T1611 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 783976 T1611 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 783979 T1611 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 783980 T1611 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 783986 T1611 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 783986 T1611 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 784090 T1611 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 784091 T1611 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 784102 T1611 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 784102 T1611 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 784107 T1611 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 784107 T1611 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 784111 T1611 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 784112 T1611 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 784116 T1611 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 784117 T1611 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 784120 T1611 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 784120 T1611 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 784124 T1611 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 784124 T1611 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 784128 T1611 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 784128 T1611 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 784132 T1611 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 784132 T1611 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 784436 T1611 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 784441 T1611 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:53785
[junit4] 2> 784442 T1611 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 784442 T1611 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 784443 T1611 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-controljetty-1386191926118
[junit4] 2> 784443 T1611 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-controljetty-1386191926118/'
[junit4] 2> 784486 T1611 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/./org.apache.solr.cloud.ShardSplitTest-controljetty-1386191926118/solr.xml
[junit4] 2> 784584 T1611 oasc.CoreContainer.<init> New CoreContainer 1149627887
[junit4] 2> 784585 T1611 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-controljetty-1386191926118/]
[junit4] 2> 784587 T1611 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 784587 T1611 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 784588 T1611 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 784588 T1611 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 784589 T1611 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 784589 T1611 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 784590 T1611 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 784590 T1611 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 784591 T1611 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 784610 T1611 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 784611 T1611 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 784611 T1611 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 784612 T1611 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:47057/solr
[junit4] 2> 784612 T1611 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 784614 T1611 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 784616 T1631 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@34597047 name:ZooKeeperConnection Watcher:127.0.0.1:47057 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 784617 T1611 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 784620 T1611 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 784628 T1633 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@44121c17 name:ZooKeeperConnection Watcher:127.0.0.1:47057/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 784628 T1611 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 784631 T1611 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 784636 T1611 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 784639 T1611 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 784646 T1611 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53785_
[junit4] 2> 784648 T1611 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53785_
[junit4] 2> 784651 T1611 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 784668 T1611 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 784671 T1611 oasc.Overseer.start Overseer (id=90845474050867203-127.0.0.1:53785_-n_0000000000) starting
[junit4] 2> 784682 T1611 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 784693 T1635 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 784694 T1611 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 784697 T1611 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 784704 T1611 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 784707 T1634 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 784712 T1636 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 784712 T1636 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 784714 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 784714 T1636 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 784715 T1634 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 784716 T1634 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:53785",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:53785_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 784717 T1634 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 784717 T1634 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 784720 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 784729 T1633 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> 785715 T1636 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 785715 T1636 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-controljetty-1386191926118/collection1
[junit4] 2> 785716 T1636 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 785717 T1636 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 785717 T1636 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 785718 T1636 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-controljetty-1386191926118/collection1/'
[junit4] 2> 785720 T1636 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-controljetty-1386191926118/collection1/lib/classes/' to classloader
[junit4] 2> 785720 T1636 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-controljetty-1386191926118/collection1/lib/README' to classloader
[junit4] 2> 785789 T1636 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 785856 T1636 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 785958 T1636 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 785969 T1636 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 786597 T1636 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 786601 T1636 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 786603 T1636 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 786609 T1636 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 786638 T1636 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 786639 T1636 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-controljetty-1386191926118/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1386191925816/control/data/
[junit4] 2> 786639 T1636 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@17e4c30c
[junit4] 2> 786640 T1636 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1386191925816/control/data
[junit4] 2> 786640 T1636 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1386191925816/control/data/index/
[junit4] 2> 786641 T1636 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1386191925816/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 786641 T1636 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1386191925816/control/data/index
[junit4] 2> 786642 T1636 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=31, maxMergedSegmentMB=94.326171875, floorSegmentMB=0.626953125, forceMergeDeletesPctAllowed=22.062916809642147, segmentsPerTier=34.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6633363402009598
[junit4] 2> 786643 T1636 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@616ef468 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@233a13aa),segFN=segments_1,generation=1}
[junit4] 2> 786643 T1636 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 786648 T1636 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 786648 T1636 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 786649 T1636 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 786649 T1636 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 786650 T1636 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 786650 T1636 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 786651 T1636 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 786651 T1636 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 786651 T1636 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 786652 T1636 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 786653 T1636 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 786653 T1636 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 786653 T1636 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 786654 T1636 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 786655 T1636 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 786655 T1636 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 786672 T1636 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 786679 T1636 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 786679 T1636 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 786680 T1636 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=11, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 786681 T1636 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@616ef468 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@233a13aa),segFN=segments_1,generation=1}
[junit4] 2> 786681 T1636 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 786682 T1636 oass.SolrIndexSearcher.<init> Opening Searcher@3495d6ea main
[junit4] 2> 786685 T1637 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3495d6ea main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 786688 T1636 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 786688 T1636 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53785 collection:control_collection shard:shard1
[junit4] 2> 786689 T1636 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 786715 T1636 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 786726 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 786727 T1636 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 786727 T1636 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C711 name=collection1 org.apache.solr.core.SolrCore@42b3c84d url=http://127.0.0.1:53785/collection1 node=127.0.0.1:53785_ C711_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:53785, core=collection1, node_name=127.0.0.1:53785_}
[junit4] 2> 786727 T1636 C711 P53785 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53785/collection1/
[junit4] 2> 786728 T1634 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 786728 T1636 C711 P53785 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 786729 T1636 C711 P53785 oasc.SyncStrategy.syncToMe http://127.0.0.1:53785/collection1/ has no replicas
[junit4] 2> 786729 T1636 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53785/collection1/ shard1
[junit4] 2> 786729 T1636 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 786732 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 786733 T1633 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> 786738 T1634 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 786741 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 786843 T1633 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> 786890 T1636 oasc.ZkController.register We are http://127.0.0.1:53785/collection1/ and leader is http://127.0.0.1:53785/collection1/
[junit4] 2> 786890 T1636 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53785
[junit4] 2> 786890 T1636 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 786890 T1636 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 786891 T1636 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 786892 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 786892 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 786893 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 786893 T1636 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 786894 T1611 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> 786895 T1611 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 786894 T1634 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 786896 T1634 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:53785",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:53785_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 786898 T1611 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 786899 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 786909 T1640 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2d3353ce name:ZooKeeperConnection Watcher:127.0.0.1:47057/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 786909 T1611 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 786910 T1611 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 786913 T1611 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 787012 T1633 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> 787012 T1640 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> 787209 T1611 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 787212 T1611 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:15778
[junit4] 2> 787213 T1611 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 787213 T1611 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 787214 T1611 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-jetty1-1386191928894
[junit4] 2> 787214 T1611 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty1-1386191928894/'
[junit4] 2> 787256 T1611 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/./org.apache.solr.cloud.ShardSplitTest-jetty1-1386191928894/solr.xml
[junit4] 2> 787352 T1611 oasc.CoreContainer.<init> New CoreContainer 1832491112
[junit4] 2> 787353 T1611 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-jetty1-1386191928894/]
[junit4] 2> 787355 T1611 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 787356 T1611 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 787356 T1611 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 787357 T1611 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 787357 T1611 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 787358 T1611 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 787358 T1611 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 787359 T1611 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 787359 T1611 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 787378 T1611 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 787378 T1611 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 787379 T1611 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 787379 T1611 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:47057/solr
[junit4] 2> 787380 T1611 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 787381 T1611 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 787384 T1651 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@294ac26b name:ZooKeeperConnection Watcher:127.0.0.1:47057 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 787384 T1611 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 787395 T1611 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 787397 T1653 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6aa901b name:ZooKeeperConnection Watcher:127.0.0.1:47057/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 787398 T1611 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 787409 T1611 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 788413 T1611 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:15778_
[junit4] 2> 788415 T1611 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:15778_
[junit4] 2> 788420 T1640 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 788420 T1653 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 788420 T1633 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 788438 T1654 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 788438 T1654 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 788440 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 788440 T1654 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 788440 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 788441 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 788442 T1634 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 788443 T1634 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:15778",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:15778_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 788443 T1634 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 788444 T1634 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 788447 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 788550 T1640 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> 788550 T1633 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> 788550 T1653 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> 789441 T1654 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 789441 T1654 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-jetty1-1386191928894/collection1
[junit4] 2> 789442 T1654 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 789442 T1654 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 789443 T1654 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 789444 T1654 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty1-1386191928894/collection1/'
[junit4] 2> 789445 T1654 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty1-1386191928894/collection1/lib/README' to classloader
[junit4] 2> 789446 T1654 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty1-1386191928894/collection1/lib/classes/' to classloader
[junit4] 2> 789515 T1654 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 789582 T1654 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 789683 T1654 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 789694 T1654 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 790300 T1654 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 790305 T1654 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 790307 T1654 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 790313 T1654 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 790340 T1654 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 790341 T1654 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-jetty1-1386191928894/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1386191925816/jetty1/
[junit4] 2> 790341 T1654 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@17e4c30c
[junit4] 2> 790342 T1654 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1386191925816/jetty1
[junit4] 2> 790342 T1654 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1386191925816/jetty1/index/
[junit4] 2> 790343 T1654 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1386191925816/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 790343 T1654 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1386191925816/jetty1/index
[junit4] 2> 790344 T1654 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=31, maxMergedSegmentMB=94.326171875, floorSegmentMB=0.626953125, forceMergeDeletesPctAllowed=22.062916809642147, segmentsPerTier=34.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6633363402009598
[junit4] 2> 790345 T1654 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7f2c551b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6c2704d4),segFN=segments_1,generation=1}
[junit4] 2> 790345 T1654 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 790351 T1654 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 790352 T1654 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 790352 T1654 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 790352 T1654 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 790353 T1654 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 790353 T1654 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 790354 T1654 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 790354 T1654 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 790355 T1654 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 790355 T1654 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 790356 T1654 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 790357 T1654 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 790357 T1654 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 790358 T1654 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 790358 T1654 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 790359 T1654 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 790376 T1654 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 790382 T1654 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 790382 T1654 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 790383 T1654 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=11, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 790384 T1654 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7f2c551b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6c2704d4),segFN=segments_1,generation=1}
[junit4] 2> 790385 T1654 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 790385 T1654 oass.SolrIndexSearcher.<init> Opening Searcher@90bfcc8 main
[junit4] 2> 790391 T1655 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@90bfcc8 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 790394 T1654 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 790394 T1654 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:15778 collection:collection1 shard:shard2
[junit4] 2> 790395 T1654 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 790479 T1654 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 790482 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 790482 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 790482 T1654 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 790482 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 790482 T1654 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C712 name=collection1 org.apache.solr.core.SolrCore@13206c3f url=http://127.0.0.1:15778/collection1 node=127.0.0.1:15778_ C712_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:15778, core=collection1, node_name=127.0.0.1:15778_}
[junit4] 2> 790483 T1654 C712 P15778 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:15778/collection1/
[junit4] 2> 790483 T1634 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 790483 T1654 C712 P15778 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 790484 T1654 C712 P15778 oasc.SyncStrategy.syncToMe http://127.0.0.1:15778/collection1/ has no replicas
[junit4] 2> 790484 T1654 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:15778/collection1/ shard2
[junit4] 2> 790485 T1654 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 790508 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 790509 T1633 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> 790509 T1640 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> 790509 T1653 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> 790614 T1634 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 790633 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 790737 T1640 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> 790737 T1653 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> 790737 T1633 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> 790767 T1654 oasc.ZkController.register We are http://127.0.0.1:15778/collection1/ and leader is http://127.0.0.1:15778/collection1/
[junit4] 2> 790767 T1654 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:15778
[junit4] 2> 790767 T1654 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 790768 T1654 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 790768 T1654 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 790769 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 790769 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 790770 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 790770 T1654 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 790771 T1611 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> 790772 T1611 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 790771 T1634 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 790773 T1634 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:15778",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:15778_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 790806 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 790910 T1633 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> 790910 T1640 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> 790910 T1653 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> 791075 T1611 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 791078 T1611 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:25651
[junit4] 2> 791079 T1611 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 791080 T1611 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 791080 T1611 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1386191932755
[junit4] 2> 791081 T1611 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1386191932755/'
[junit4] 2> 791123 T1611 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/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1386191932755/solr.xml
[junit4] 2> 791219 T1611 oasc.CoreContainer.<init> New CoreContainer 1875555644
[junit4] 2> 791220 T1611 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1386191932755/]
[junit4] 2> 791222 T1611 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 791223 T1611 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 791223 T1611 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 791224 T1611 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 791224 T1611 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 791225 T1611 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 791225 T1611 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 791226 T1611 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 791226 T1611 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 791245 T1611 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 791245 T1611 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 791246 T1611 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 791246 T1611 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:47057/solr
[junit4] 2> 791247 T1611 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 791248 T1611 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 791255 T1667 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@889089f name:ZooKeeperConnection Watcher:127.0.0.1:47057 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 791256 T1611 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 791259 T1611 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 791266 T1669 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2c3069b3 name:ZooKeeperConnection Watcher:127.0.0.1:47057/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 791267 T1611 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 791272 T1611 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 792276 T1611 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:25651_
[junit4] 2> 792281 T1611 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:25651_
[junit4] 2> 792286 T1653 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 792286 T1669 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 792286 T1633 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 792286 T1640 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 792303 T1670 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 792303 T1670 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 792305 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 792305 T1670 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 792305 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 792306 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 792307 T1634 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 792308 T1634 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:25651",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:25651_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 792308 T1634 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 792308 T1634 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 792313 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 792417 T1669 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> 792417 T1633 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> 792417 T1653 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> 792417 T1640 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> 793306 T1670 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 793306 T1670 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1386191932755/collection1
[junit4] 2> 793306 T1670 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 793307 T1670 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 793307 T1670 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 793309 T1670 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1386191932755/collection1/'
[junit4] 2> 793311 T1670 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty2-1386191932755/collection1/lib/classes/' to classloader
[junit4] 2> 793311 T1670 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty2-1386191932755/collection1/lib/README' to classloader
[junit4] 2> 793381 T1670 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 793448 T1670 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 793550 T1670 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 793585 T1670 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 794187 T1670 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 794191 T1670 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 794194 T1670 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 794199 T1670 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 794227 T1670 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 794228 T1670 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1386191932755/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1386191925816/jetty2/
[junit4] 2> 794228 T1670 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@17e4c30c
[junit4] 2> 794230 T1670 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1386191925816/jetty2
[junit4] 2> 794230 T1670 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1386191925816/jetty2/index/
[junit4] 2> 794230 T1670 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1386191925816/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 794231 T1670 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1386191925816/jetty2/index
[junit4] 2> 794231 T1670 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=31, maxMergedSegmentMB=94.326171875, floorSegmentMB=0.626953125, forceMergeDeletesPctAllowed=22.062916809642147, segmentsPerTier=34.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6633363402009598
[junit4] 2> 794232 T1670 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@30fb7064 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@712452ae),segFN=segments_1,generation=1}
[junit4] 2> 794233 T1670 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 794239 T1670 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 794239 T1670 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 794240 T1670 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 794240 T1670 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 794240 T1670 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 794241 T1670 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 794242 T1670 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 794242 T1670 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 794243 T1670 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 794243 T1670 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 794244 T1670 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 794244 T1670 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 794245 T1670 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 794246 T1670 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 794246 T1670 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 794247 T1670 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 794264 T1670 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 794269 T1670 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 794270 T1670 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 794271 T1670 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=11, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 794271 T1670 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@30fb7064 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@712452ae),segFN=segments_1,generation=1}
[junit4] 2> 794272 T1670 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 794272 T1670 oass.SolrIndexSearcher.<init> Opening Searcher@74d7013e main
[junit4] 2> 794278 T1671 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@74d7013e main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 794281 T1670 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 794281 T1670 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:25651 collection:collection1 shard:shard1
[junit4] 2> 794282 T1670 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 794302 T1670 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 794313 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 794314 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 794314 T1670 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 794314 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 794314 T1670 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C713 name=collection1 org.apache.solr.core.SolrCore@7ea976ee url=http://127.0.0.1:25651/collection1 node=127.0.0.1:25651_ C713_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:25651, core=collection1, node_name=127.0.0.1:25651_}
[junit4] 2> 794315 T1670 C713 P25651 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:25651/collection1/
[junit4] 2> 794315 T1634 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 794315 T1670 C713 P25651 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 794316 T1670 C713 P25651 oasc.SyncStrategy.syncToMe http://127.0.0.1:25651/collection1/ has no replicas
[junit4] 2> 794316 T1670 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:25651/collection1/ shard1
[junit4] 2> 794317 T1670 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 794319 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 794328 T1633 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> 794328 T1640 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> 794329 T1669 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> 794328 T1653 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> 794343 T1634 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 794346 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 794449 T1669 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> 794449 T1633 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> 794449 T1653 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> 794449 T1640 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> 794495 T1670 oasc.ZkController.register We are http://127.0.0.1:25651/collection1/ and leader is http://127.0.0.1:25651/collection1/
[junit4] 2> 794495 T1670 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:25651
[junit4] 2> 794495 T1670 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 794495 T1670 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 794496 T1670 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 794497 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 794497 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 794498 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 794498 T1670 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 794499 T1634 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 794499 T1611 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> 794500 T1611 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 794500 T1634 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:25651",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:25651_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 794503 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 794607 T1633 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> 794607 T1640 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> 794607 T1669 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> 794607 T1653 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> 794795 T1611 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 794798 T1611 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:37023
[junit4] 2> 794799 T1611 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 794800 T1611 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 794800 T1611 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1386191936482
[junit4] 2> 794801 T1611 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1386191936482/'
[junit4] 2> 794843 T1611 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/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1386191936482/solr.xml
[junit4] 2> 794939 T1611 oasc.CoreContainer.<init> New CoreContainer 704952586
[junit4] 2> 794940 T1611 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1386191936482/]
[junit4] 2> 794942 T1611 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 794942 T1611 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 794943 T1611 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 794943 T1611 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 794944 T1611 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 794944 T1611 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 794945 T1611 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 794945 T1611 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 794946 T1611 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 794964 T1611 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 794965 T1611 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 794965 T1611 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 794966 T1611 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:47057/solr
[junit4] 2> 794967 T1611 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 794968 T1611 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 794970 T1683 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ff8f16d name:ZooKeeperConnection Watcher:127.0.0.1:47057 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 794971 T1611 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 794974 T1611 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 794985 T1685 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c544e57 name:ZooKeeperConnection Watcher:127.0.0.1:47057/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 794985 T1611 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 794996 T1611 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 795999 T1611 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37023_
[junit4] 2> 796004 T1611 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37023_
[junit4] 2> 796008 T1640 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 796008 T1633 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 796008 T1685 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 796008 T1653 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 796008 T1669 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 796034 T1686 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 796035 T1686 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 796036 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 796036 T1686 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 796036 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 796037 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 796038 T1634 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 796039 T1634 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:37023",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:37023_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 796039 T1634 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 796039 T1634 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 796042 T1633 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 796145 T1640 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 796145 T1653 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 796145 T1633 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 796145 T1685 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 796145 T1669 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 797038 T1686 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 797038 T1686 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1386191936482/collection1
[junit4] 2> 797039 T1686 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 797039 T1686 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 797040 T1686 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 797041 T1686 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1386191936482/collection1/'
[junit4] 2> 797043 T1686 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty3-1386191936482/collection1/lib/README' to classloader
[junit4] 2> 797044 T1686 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ShardSplitTest-jetty3-1386191936482/collection1/lib/classes/' to classloader
[junit4] 2> 797112 T1686 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
[junit4] 2> 797180 T1686 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 797281 T1686 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 797292 T1686 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 797908 T1686 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 797913 T1686 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 797915 T1686 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 797920 T1686 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 797947 T1686 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 797948 T1686 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1386191936482/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1386191925816/jetty3/
[junit4] 2> 797948 T1686 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@17e4c30c
[junit4] 2> 797949 T1686 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1386191925816/jetty3
[junit4] 2> 797949 T1686 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1386191925816/jetty3/index/
[junit4] 2> 797950 T1686 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1386191925816/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 797950 T1686 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1386191925816/jetty3/index
[junit4] 2> 797950 T1686 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=31, maxMergedSegmentMB=94.326171875, floorSegmentMB=0.626953125, forceMergeDeletesPctAllowed=22.062916809642147, segmentsPerTier=34.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6633363402009598
[junit4] 2> 797951 T1686 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@39b156d4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4accd445),segFN=segments_1,generation=1}
[junit4] 2> 797952 T1686 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 797957 T1686 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 797958 T1686 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 797958 T1686 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 797958 T1686 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 797959 T1686 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 797959 T1686 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 797960 T1686 oasup.UpdateRequestPr
[...truncated too long message...]
.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:169)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:166)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:166)
[junit4] 2> at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:66)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:280)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 935539 T1702 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 935539 T1702 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> 935540 T1702 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 935540 T1702 oasc.LeaderElector$1.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:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:252)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 935559 T1611 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 53785
[junit4] 2> !!!! WARNING: best effort to remove /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ShardSplitTest-1386191925816 FAILED !!!!!
[junit4] 2> 935560 T1611 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 935561 T1611 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:47057 47057
[junit4] 1> /solr/configs/conf1/solrconfig.snippet.randomindexconfig.xml (0)
[junit4] 1> DATA: ...supressed...
[junit4] 1> /solr/configs/conf1/stopwords.txt (0)
[junit4] 1> DATA: ...supressed...
[junit4] 1> /solr/configs/conf1/enumsConfig.xml (0)
[junit4] 1> DATA: ...supressed...
[junit4] 1> /solr/configs/conf1/schema.xml (0)
[junit4] 1> DATA: ...supressed...
[junit4] 1> /solr/configs/conf1/currency.xml (0)
[junit4] 1> DATA: ...supressed...
[junit4] 1> /solr/configs/conf1/mapping-ISOLatin1Accent.txt (0)
[junit4] 1> DATA: ...supressed...
[junit4] 1> /solr/configs/conf1/solrconfig.xml (0)
[junit4] 1> DATA: ...supressed...
[junit4] 1> /solr/overseer_elect (2)
[junit4] 1> /solr/overseer_elect/election (5)
[junit4] 1> /solr/overseer_elect/election/90845474050867206-127.0.0.1:15778_-n_0000000001 (0)
[junit4] 1> /solr/overseer_elect/election/90845474050867203-127.0.0.1:53785_-n_0000000000 (0)
[junit4] 1> /solr/overseer_elect/election/90845474050867210-127.0.0.1:37023_-n_0000000003 (0)
[junit4] 1> /solr/overseer_elect/election/90845474050867212-127.0.0.1:38366_-n_0000000004 (0)
[junit4] 1> /solr/overseer_elect/election/90845474050867208-127.0.0.1:25651_-n_0000000002 (0)
[junit4] 1> /solr/overseer_elect/leader (0)
[junit4] 1> DATA:
[junit4] 1> {"id":"90845474050867203-127.0.0.1:53785_-n_0000000000"}
[junit4] 1> /zookeeper (1)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ShardSplitTest -Dtests.method=testDistribSearch -Dtests.seed=347428AAA79D707F -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_NI -Dtests.timezone=Asia/Kolkata -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 152s J1 | ShardSplitTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: Wrong doc count on shard1_0 expected:<269> but was:<195>
[junit4] > at __randomizedtesting.SeedInfo.seed([347428AAA79D707F:B592A6B2D0C21043]:0)
[junit4] > at org.apache.solr.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:477)
[junit4] > at org.apache.solr.cloud.ShardSplitTest.splitByUniqueKeyTest(ShardSplitTest.java:249)
[junit4] > at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:113)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:843)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] 2> 935576 T1611 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 151754 T1610 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4] 2> 935585 T1685 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene45, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=es_NI, timezone=Asia/Kolkata
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=372661472,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [OpenCloseCoreStressTest, ShardRoutingCustomTest, TestSchemaResource, SolrPluginUtilsTest, CachingDirectoryFactoryTest, JsonLoaderTest, TestFiltering, TestIndexSearcher, ChaosMonkeyNothingIsSafeTest, TestManagedSchema, TestSchemaNameResource, SOLR749Test, SpellPossibilityIteratorTest, TestPseudoReturnFields, TestSweetSpotSimilarityFactory, BadIndexSchemaTest, SolrIndexSplitterTest, DocValuesTest, TestBinaryResponseWriter, CustomCollectionTest, HdfsCollectionsAPIDistributedZkTest, QueryElevationComponentTest, TestShardHandlerFactory, ResponseLogComponentTest, TestIBSimilarityFactory, PluginInfoTest, SimpleFacetsTest, TestFuzzyAnalyzedSuggestions, TestLuceneMatchVersion, SystemInfoHandlerTest, TestStressVersions, CacheHeaderTest, HighlighterConfigTest, TestHashPartitioner, SpatialFilterTest, TestQuerySenderNoQuery, TestLazyCores, DateMathParserTest, TestImplicitCoreProperties, TestFastOutputStream, TestCodecSupport, BlockDirectoryTest, IndexBasedSpellCheckerTest, TestBM25SimilarityFactory, TestFileDictionaryLookup, RegexBoostProcessorTest, BlockCacheTest, PathHierarchyTokenizerFactoryTest, SignatureUpdateProcessorFactoryTest, TestRandomMergePolicy, CoreAdminCreateDiscoverTest, TestSolrQueryParserResource, TestCoreContainer, TestDistributedSearch, TestFieldResource, ZkControllerTest, TestSolrXMLSerializer, DOMUtilTest, SolrRequestParserTest, TestClassNameShortening, CopyFieldTest, RequestHandlersTest, CSVRequestHandlerTest, DocValuesMultiTest, TermVectorComponentDistributedTest, TestReversedWildcardFilterFactory, StatsComponentTest, MultiTermTest, ShardSplitTest]
[junit4] Completed on J1 in 152.30s, 1 test, 1 failure <<< FAILURES!
[...truncated 681 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:426: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:406: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:39: 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:491: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:1307: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:940: There were test failures: 347 suites, 1516 tests, 1 failure, 34 ignored (6 assumptions)
Total time: 68 minutes 53 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure