You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/02/22 03:32:11 UTC
[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 1322 -
Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/1322/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.cloud.ShardSplitTest.testDistribSearch
Error Message:
Wrong doc count on shard1_0 expected:<124> but was:<123>
Stack Trace:
java.lang.AssertionError: Wrong doc count on shard1_0 expected:<124> but was:<123>
at __randomizedtesting.SeedInfo.seed([E4F70E40EC0E8E09:651180589B51EE35]: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:476)
at org.apache.solr.cloud.ShardSplitTest.splitByUniqueKeyTest(ShardSplitTest.java:248)
at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:112)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:870)
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:744)
Build Log:
[...truncated 10287 lines...]
[junit4] Suite: org.apache.solr.cloud.ShardSplitTest
[junit4] 2> 1106660 T3267 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 1106661 T3267 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /o/r
[junit4] 2> 1106667 T3267 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1393033847540
[junit4] 2> 1106668 T3267 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1106669 T3268 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1106779 T3267 oasc.ZkTestServer.run start zk server on port:52049
[junit4] 2> 1106789 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1106794 T3274 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13aa84e8 name:ZooKeeperConnection Watcher:127.0.0.1:52049 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1106795 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1106795 T3267 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1106806 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1106810 T3276 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@395b8405 name:ZooKeeperConnection Watcher:127.0.0.1:52049/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1106811 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1106811 T3267 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1106819 T3267 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1106826 T3267 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1106832 T3267 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1106841 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1106842 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1106853 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 1106854 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1106861 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1106862 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1106870 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1106871 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1106878 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1106878 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1106886 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1106887 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1106894 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 1106895 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 1106902 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1106902 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1106909 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1106909 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1106916 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1106916 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1106924 T3267 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1106924 T3267 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1107322 T3267 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1107332 T3267 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52052
[junit4] 2> 1107335 T3267 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1107339 T3267 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1107341 T3267 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1393033847807
[junit4] 2> 1107342 T3267 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1393033847807/'
[junit4] 2> 1107395 T3267 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1393033847807/solr.xml
[junit4] 2> 1107508 T3267 oasc.CoreContainer.<init> New CoreContainer 233159595
[junit4] 2> 1107508 T3267 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1393033847807/]
[junit4] 2> 1107510 T3267 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1107510 T3267 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1107511 T3267 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1107511 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1107511 T3267 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1107511 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1107512 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1107512 T3267 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1107512 T3267 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1107522 T3267 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1107523 T3267 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1107523 T3267 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1107524 T3267 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52049/solr
[junit4] 2> 1107524 T3267 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1107526 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1107530 T3287 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6583dead name:ZooKeeperConnection Watcher:127.0.0.1:52049 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1107530 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1107537 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1107541 T3289 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6f56441b name:ZooKeeperConnection Watcher:127.0.0.1:52049/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1107541 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1107546 T3267 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1107556 T3267 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1107568 T3267 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1107574 T3267 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52052_o%2Fr
[junit4] 2> 1107577 T3267 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52052_o%2Fr
[junit4] 2> 1107587 T3267 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1107593 T3267 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1107604 T3267 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:52052_o%2Fr
[junit4] 2> 1107605 T3267 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1107612 T3267 oasc.Overseer.start Overseer (id=91293866232774659-127.0.0.1:52052_o%2Fr-n_0000000000) starting
[junit4] 2> 1107621 T3267 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1107631 T3291 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1107634 T3291 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1107634 T3267 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1107642 T3267 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1107648 T3267 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1107656 T3290 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1107663 T3292 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1107663 T3292 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1107666 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1107666 T3292 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1107671 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1107672 T3290 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:52052/o/r",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52052_o%2Fr",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1107672 T3290 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 1107673 T3290 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1107679 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1107682 T3289 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> 1108668 T3292 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1108669 T3292 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1393033847807/collection1
[junit4] 2> 1108670 T3292 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1108673 T3292 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1108673 T3292 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1108678 T3292 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1108678 T3292 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1393033847807/collection1/'
[junit4] 2> 1108680 T3292 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1393033847807/collection1/lib/classes/' to classloader
[junit4] 2> 1108680 T3292 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1393033847807/collection1/lib/README' to classloader
[junit4] 2> 1108761 T3292 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 1108820 T3292 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1108824 T3292 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1108833 T3292 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1109364 T3292 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1109367 T3292 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1109369 T3292 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1109376 T3292 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1109437 T3292 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1109438 T3292 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1393033847807/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1393033847540/control/data/
[junit4] 2> 1109438 T3292 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@510b6523
[junit4] 2> 1109439 T3292 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1393033847540/control/data
[junit4] 2> 1109439 T3292 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1393033847540/control/data/index/
[junit4] 2> 1109439 T3292 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1393033847540/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1109439 T3292 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1393033847540/control/data/index
[junit4] 2> 1109440 T3292 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=21, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1109440 T3292 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@7de65357 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@a8d808f),segFN=segments_1,generation=1}
[junit4] 2> 1109441 T3292 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1109444 T3292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1109445 T3292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1109445 T3292 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1109445 T3292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1109445 T3292 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1109446 T3292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1109447 T3292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1109447 T3292 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1109448 T3292 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1109448 T3292 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1109449 T3292 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1109449 T3292 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1109450 T3292 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1109450 T3292 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1109450 T3292 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1109451 T3292 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1109463 T3292 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1109470 T3292 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1109472 T3292 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1109472 T3292 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=18, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=67.7900390625, floorSegmentMB=0.244140625, forceMergeDeletesPctAllowed=5.25784342504377, segmentsPerTier=14.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1109473 T3292 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@7de65357 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@a8d808f),segFN=segments_1,generation=1}
[junit4] 2> 1109473 T3292 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1109473 T3292 oass.SolrIndexSearcher.<init> Opening Searcher@2de2a471[collection1] main
[junit4] 2> 1109480 T3293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2de2a471[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1109481 T3292 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1109483 T3267 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 1109483 T3267 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1109483 T3296 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52052/o/r collection:control_collection shard:shard1
[junit4] 2> 1109486 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1109487 T3296 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1109489 T3298 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b5c7b7f name:ZooKeeperConnection Watcher:127.0.0.1:52049/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1109490 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1109493 T3267 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1109501 T3267 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 1109505 T3296 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1109510 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1109514 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1109517 T3296 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1109517 T3296 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C698 name=collection1 org.apache.solr.core.SolrCore@5436804a url=http://127.0.0.1:52052/o/r/collection1 node=127.0.0.1:52052_o%2Fr C698_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:52052/o/r, core=collection1, node_name=127.0.0.1:52052_o%2Fr}
[junit4] 2> 1109517 T3296 C698 P52052 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52052/o/r/collection1/
[junit4] 2> 1109517 T3296 C698 P52052 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1109518 T3296 C698 P52052 oasc.SyncStrategy.syncToMe http://127.0.0.1:52052/o/r/collection1/ has no replicas
[junit4] 2> 1109518 T3296 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52052/o/r/collection1/ shard1
[junit4] 2> 1109518 T3296 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1109541 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1109545 T3298 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> 1109547 T3289 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> 1109561 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1109576 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1109682 T3298 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> 1109683 T3289 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> 1109705 T3296 oasc.ZkController.register We are http://127.0.0.1:52052/o/r/collection1/ and leader is http://127.0.0.1:52052/o/r/collection1/
[junit4] 2> 1109705 T3296 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52052/o/r
[junit4] 2> 1109706 T3296 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1109706 T3296 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1109706 T3296 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1109709 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1109709 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1109709 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1109711 T3296 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1109716 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1109717 T3290 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:52052/o/r",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52052_o%2Fr",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1109723 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1109828 T3289 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> 1109830 T3298 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> 1109890 T3267 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 1109892 T3267 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1109896 T3267 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52056
[junit4] 2> 1109897 T3267 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1109897 T3267 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1109897 T3267 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1393033850375
[junit4] 2> 1109898 T3267 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1393033850375/'
[junit4] 2> 1109932 T3267 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1393033850375/solr.xml
[junit4] 2> 1109998 T3267 oasc.CoreContainer.<init> New CoreContainer 1579081278
[junit4] 2> 1109998 T3267 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1393033850375/]
[junit4] 2> 1109999 T3267 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1110000 T3267 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1110000 T3267 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1110000 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1110000 T3267 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1110001 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1110001 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1110001 T3267 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1110002 T3267 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1110011 T3267 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1110011 T3267 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1110011 T3267 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1110012 T3267 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52049/solr
[junit4] 2> 1110012 T3267 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1110013 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1110018 T3309 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3c90e8b8 name:ZooKeeperConnection Watcher:127.0.0.1:52049 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1110019 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1110025 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1110030 T3311 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55ab1ae6 name:ZooKeeperConnection Watcher:127.0.0.1:52049/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1110030 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1110049 T3267 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1111062 T3267 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52056_o%2Fr
[junit4] 2> 1111065 T3267 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52056_o%2Fr
[junit4] 2> 1111074 T3298 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1111074 T3311 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1111075 T3289 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1111097 T3312 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1111097 T3312 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1111101 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1111102 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1111102 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1111102 T3312 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1111105 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1111107 T3290 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:52056/o/r",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52056_o%2Fr",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1111107 T3290 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 1111107 T3290 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1111115 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1111226 T3311 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> 1111226 T3298 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> 1111226 T3289 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> 1112104 T3312 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1112104 T3312 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1393033850375/collection1
[junit4] 2> 1112105 T3312 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1112107 T3312 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1112107 T3312 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1112110 T3312 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1112110 T3312 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1393033850375/collection1/'
[junit4] 2> 1112112 T3312 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1393033850375/collection1/lib/classes/' to classloader
[junit4] 2> 1112113 T3312 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1393033850375/collection1/lib/README' to classloader
[junit4] 2> 1112185 T3312 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 1112247 T3312 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1112251 T3312 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1112260 T3312 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1112915 T3312 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1112918 T3312 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1112920 T3312 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1112926 T3312 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1112991 T3312 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1112991 T3312 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1393033850375/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty1/
[junit4] 2> 1112991 T3312 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@510b6523
[junit4] 2> 1112992 T3312 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty1
[junit4] 2> 1112992 T3312 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty1/index/
[junit4] 2> 1112992 T3312 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 1112993 T3312 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty1/index
[junit4] 2> 1112993 T3312 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=21, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1112994 T3312 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@77d45a42 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5f5e110d),segFN=segments_1,generation=1}
[junit4] 2> 1112994 T3312 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1112999 T3312 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1112999 T3312 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1112999 T3312 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1113000 T3312 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1113000 T3312 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1113000 T3312 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1113001 T3312 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1113001 T3312 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1113001 T3312 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1113002 T3312 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1113003 T3312 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1113003 T3312 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1113003 T3312 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1113004 T3312 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1113004 T3312 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1113005 T3312 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1113014 T3312 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1113019 T3312 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1113019 T3312 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1113020 T3312 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=18, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=67.7900390625, floorSegmentMB=0.244140625, forceMergeDeletesPctAllowed=5.25784342504377, segmentsPerTier=14.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1113020 T3312 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@77d45a42 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5f5e110d),segFN=segments_1,generation=1}
[junit4] 2> 1113021 T3312 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1113021 T3312 oass.SolrIndexSearcher.<init> Opening Searcher@11b6089[collection1] main
[junit4] 2> 1113026 T3313 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@11b6089[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1113029 T3312 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1113031 T3267 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 1113031 T3267 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1113031 T3316 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52056/o/r collection:collection1 shard:shard2
[junit4] 2> 1113034 T3316 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1113048 T3316 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 1113054 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1113055 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1113055 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1113056 T3316 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1113056 T3316 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C699 name=collection1 org.apache.solr.core.SolrCore@4dfdf4bc url=http://127.0.0.1:52056/o/r/collection1 node=127.0.0.1:52056_o%2Fr C699_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:52056/o/r, core=collection1, node_name=127.0.0.1:52056_o%2Fr}
[junit4] 2> 1113056 T3316 C699 P52056 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52056/o/r/collection1/
[junit4] 2> 1113056 T3316 C699 P52056 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1113057 T3316 C699 P52056 oasc.SyncStrategy.syncToMe http://127.0.0.1:52056/o/r/collection1/ has no replicas
[junit4] 2> 1113057 T3316 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52056/o/r/collection1/ shard2
[junit4] 2> 1113057 T3316 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1113064 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1113072 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1113073 T3289 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> 1113075 T3311 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> 1113075 T3298 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> 1113091 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1113097 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1113204 T3289 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> 1113205 T3298 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> 1113206 T3311 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> 1113239 T3316 oasc.ZkController.register We are http://127.0.0.1:52056/o/r/collection1/ and leader is http://127.0.0.1:52056/o/r/collection1/
[junit4] 2> 1113239 T3316 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52056/o/r
[junit4] 2> 1113240 T3316 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1113240 T3316 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1113240 T3316 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1113244 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1113244 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1113245 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1113251 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1113253 T3316 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1113255 T3290 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:52056/o/r",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52056_o%2Fr",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1113264 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1113370 T3311 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> 1113372 T3289 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> 1113372 T3298 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> 1113427 T3267 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 1113428 T3267 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1113433 T3267 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52059
[junit4] 2> 1113435 T3267 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1113435 T3267 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1113436 T3267 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-jetty2-1393033853905
[junit4] 2> 1113436 T3267 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty2-1393033853905/'
[junit4] 2> 1113475 T3267 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1393033853905/solr.xml
[junit4] 2> 1113554 T3267 oasc.CoreContainer.<init> New CoreContainer 2138793577
[junit4] 2> 1113555 T3267 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-jetty2-1393033853905/]
[junit4] 2> 1113557 T3267 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1113557 T3267 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1113558 T3267 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1113558 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1113558 T3267 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1113558 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1113559 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1113559 T3267 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1113560 T3267 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1113571 T3267 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1113572 T3267 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1113572 T3267 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1113572 T3267 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52049/solr
[junit4] 2> 1113573 T3267 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1113574 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1113579 T3327 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7e80b8e1 name:ZooKeeperConnection Watcher:127.0.0.1:52049 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1113579 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1113584 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1113589 T3329 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@575d30a0 name:ZooKeeperConnection Watcher:127.0.0.1:52049/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1113590 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1113605 T3267 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1114615 T3267 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52059_o%2Fr
[junit4] 2> 1114619 T3267 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52059_o%2Fr
[junit4] 2> 1114634 T3329 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1114635 T3289 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1114635 T3311 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1114635 T3298 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1114660 T3330 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1114660 T3330 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1114664 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1114665 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1114665 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1114664 T3330 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1114670 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1114672 T3290 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:52059/o/r",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52059_o%2Fr",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1114673 T3290 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1114673 T3290 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1114683 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1114795 T3289 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> 1114795 T3298 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> 1114796 T3329 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> 1114796 T3311 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> 1115669 T3330 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1115670 T3330 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-jetty2-1393033853905/collection1
[junit4] 2> 1115670 T3330 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1115671 T3330 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1115672 T3330 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1115674 T3330 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1115674 T3330 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty2-1393033853905/collection1/'
[junit4] 2> 1115676 T3330 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1393033853905/collection1/lib/classes/' to classloader
[junit4] 2> 1115677 T3330 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1393033853905/collection1/lib/README' to classloader
[junit4] 2> 1115745 T3330 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 1115811 T3330 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1115815 T3330 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1115825 T3330 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1116400 T3330 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1116403 T3330 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1116404 T3330 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1116412 T3330 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1116510 T3330 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1116511 T3330 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-jetty2-1393033853905/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty2/
[junit4] 2> 1116511 T3330 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@510b6523
[junit4] 2> 1116512 T3330 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty2
[junit4] 2> 1116513 T3330 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty2/index/
[junit4] 2> 1116513 T3330 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 1116513 T3330 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty2/index
[junit4] 2> 1116514 T3330 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=21, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1116515 T3330 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@71550379 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6086a0c1),segFN=segments_1,generation=1}
[junit4] 2> 1116516 T3330 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1116521 T3330 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1116521 T3330 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1116522 T3330 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1116522 T3330 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1116522 T3330 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1116522 T3330 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1116523 T3330 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1116524 T3330 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1116524 T3330 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1116525 T3330 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1116526 T3330 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1116526 T3330 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1116527 T3330 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1116528 T3330 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1116528 T3330 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1116530 T3330 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1116540 T3330 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1116544 T3330 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1116545 T3330 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1116546 T3330 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=18, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=67.7900390625, floorSegmentMB=0.244140625, forceMergeDeletesPctAllowed=5.25784342504377, segmentsPerTier=14.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1116546 T3330 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@71550379 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6086a0c1),segFN=segments_1,generation=1}
[junit4] 2> 1116546 T3330 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1116547 T3330 oass.SolrIndexSearcher.<init> Opening Searcher@567be7ee[collection1] main
[junit4] 2> 1116551 T3331 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@567be7ee[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1116554 T3330 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1116556 T3267 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 1116557 T3267 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1116556 T3334 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52059/o/r collection:collection1 shard:shard1
[junit4] 2> 1116560 T3334 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1116577 T3334 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1116585 T3334 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1116585 T3334 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C700 name=collection1 org.apache.solr.core.SolrCore@42ac6287 url=http://127.0.0.1:52059/o/r/collection1 node=127.0.0.1:52059_o%2Fr C700_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:52059/o/r, core=collection1, node_name=127.0.0.1:52059_o%2Fr}
[junit4] 2> 1116586 T3334 C700 P52059 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52059/o/r/collection1/
[junit4] 2> 1116587 T3334 C700 P52059 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1116587 T3334 C700 P52059 oasc.SyncStrategy.syncToMe http://127.0.0.1:52059/o/r/collection1/ has no replicas
[junit4] 2> 1116587 T3334 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52059/o/r/collection1/ shard1
[junit4] 2> 1116588 T3334 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1116589 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116590 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116590 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116597 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1116615 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116620 T3311 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> 1116621 T3298 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> 1116621 T3329 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> 1116622 T3289 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> 1116634 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1116641 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116747 T3298 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> 1116747 T3289 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> 1116749 T3329 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> 1116752 T3311 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> 1116781 T3334 oasc.ZkController.register We are http://127.0.0.1:52059/o/r/collection1/ and leader is http://127.0.0.1:52059/o/r/collection1/
[junit4] 2> 1116781 T3334 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52059/o/r
[junit4] 2> 1116782 T3334 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1116782 T3334 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1116782 T3334 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1116786 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116786 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116787 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116789 T3334 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1116791 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1116792 T3290 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:52059/o/r",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52059_o%2Fr",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 1116804 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1116911 T3311 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> 1116912 T3298 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> 1116913 T3289 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> 1116913 T3329 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> 1116937 T3267 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 1116938 T3267 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1116942 T3267 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52062
[junit4] 2> 1116943 T3267 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1116943 T3267 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1116944 T3267 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-jetty3-1393033857431
[junit4] 2> 1116944 T3267 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty3-1393033857431/'
[junit4] 2> 1116974 T3267 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1393033857431/solr.xml
[junit4] 2> 1117060 T3267 oasc.CoreContainer.<init> New CoreContainer 804946542
[junit4] 2> 1117060 T3267 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-jetty3-1393033857431/]
[junit4] 2> 1117062 T3267 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1117062 T3267 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1117063 T3267 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1117063 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1117063 T3267 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1117063 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1117064 T3267 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1117064 T3267 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1117064 T3267 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1117075 T3267 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1117075 T3267 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1117076 T3267 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1117076 T3267 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52049/solr
[junit4] 2> 1117076 T3267 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1117078 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1117084 T3345 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@67891c5d name:ZooKeeperConnection Watcher:127.0.0.1:52049 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1117086 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1117093 T3267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1117098 T3347 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6f83cbb6 name:ZooKeeperConnection Watcher:127.0.0.1:52049/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1117099 T3267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1117111 T3267 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1118126 T3267 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52062_o%2Fr
[junit4] 2> 1118128 T3267 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52062_o%2Fr
[junit4] 2> 1118143 T3311 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1118144 T3289 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1118145 T3298 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1118145 T3329 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1118145 T3347 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1118176 T3348 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1118177 T3348 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1118183 T3348 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1118183 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1118185 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1118185 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1118193 T3290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1118196 T3290 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:52062/o/r",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52062_o%2Fr",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1118197 T3290 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1118197 T3290 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1118212 T3289 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1118320 T3289 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> 1118321 T3298 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> 1118320 T3311 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> 1118320 T3329 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> 1118320 T3347 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> 1119186 T3348 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1119187 T3348 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-jetty3-1393033857431/collection1
[junit4] 2> 1119187 T3348 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1119190 T3348 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1119190 T3348 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1119194 T3348 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1119195 T3348 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty3-1393033857431/collection1/'
[junit4] 2> 1119197 T3348 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1393033857431/collection1/lib/classes/' to classloader
[junit4] 2> 1119197 T3348 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1393033857431/collection1/lib/README' to classloader
[junit4] 2> 1119259 T3348 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 1119315 T3348 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1119319 T3348 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1119327 T3348 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1119859 T3348 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1119864 T3348 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1119867 T3348 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1119874 T3348 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1119945 T3348 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1119946 T3348 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-jetty3-1393033857431/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty3/
[junit4] 2> 1119947 T3348 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@510b6523
[junit4] 2> 1119947 T3348 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty3
[junit4] 2> 1119948 T3348 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty3/index/
[junit4] 2> 1119948 T3348 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 1119948 T3348 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1393033847540/jetty3/index
[junit4] 2> 1119949 T3348 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=21, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1119950 T3348 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@62010223 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@315cb70e),segFN=segments_1,generation=1}
[junit4] 2> 1119950 T3348 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1119955 T3348 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1119956 T3348 oasup.UpdateRequestProcessorChain.i
[...truncated too long message...]
b04
[junit4] 2> 1163428 T3366 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=2,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=127,cumulative_deletesById=72,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=8084,transaction_logs_total_number=1}
[junit4] 2> 1163430 T3366 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 1163430 T3366 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 1163430 T3366 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 1163432 T3366 oasc.SolrCore.closeSearcher [collection1_shard1_0_replica2] Closing main searcher on request.
[junit4] 2> 1163432 T3366 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1163433 T3366 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ShardSplitTest-jetty4-1393033860871/collection1_shard1_0_replica2/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-jetty4-1393033860871/collection1_shard1_0_replica2/data;done=false>>]
[junit4] 2> 1163433 T3366 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ShardSplitTest-jetty4-1393033860871/collection1_shard1_0_replica2/data
[junit4] 2> 1163433 T3366 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ShardSplitTest-jetty4-1393033860871/collection1_shard1_0_replica2/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-jetty4-1393033860871/collection1_shard1_0_replica2/data/index;done=false>>]
[junit4] 2> 1163434 T3366 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ShardSplitTest-jetty4-1393033860871/collection1_shard1_0_replica2/data/index
[junit4] 2> 1163434 T3366 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1_1/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:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:254)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1163435 T3366 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:254)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1163435 T3366 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1163436 T3366 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:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:254)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> NOTE: test params are: codec=Asserting, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=en_IE, timezone=Asia/Kuala_Lumpur
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_51 (64-bit)/cpus=2,threads=1,free=279332824,total=499122176
[junit4] 2> NOTE: All tests run in this JVM: [TestInitQParser, OpenExchangeRatesOrgProviderTest, TestSerializedLuceneMatchVersion, TestRandomMergePolicy, EnumFieldTest, TestFoldingMultitermQuery, TestReplicationHandler, TestStressVersions, TestClassNameShortening, TestSolrJ, TestBlendedInfixSuggestions, CurrencyFieldOpenExchangeTest, CoreContainerCoreInitFailuresTest, UpdateParamsTest, TestLFUCache, BasicZkTest, TestValueSourceCache, TestRecovery, MoreLikeThisHandlerTest, EchoParamsTest, RemoteQueryErrorTest, FieldMutatingUpdateProcessorTest, TestDistributedSearch, LoggingHandlerTest, StressHdfsTest, UUIDFieldTest, SuggesterTest, DirectUpdateHandlerTest, DistributedQueryElevationComponentTest, DistribCursorPagingTest, ZkSolrClientTest, IndexBasedSpellCheckerTest, TestLMJelinekMercerSimilarityFactory, StandardRequestHandlerTest, CoreMergeIndexesAdminHandlerTest, BadIndexSchemaTest, TestSystemIdResolver, DistributedDebugComponentTest, TestAddFieldRealTimeGet, MigrateRouteKeyTest, CollectionsAPIDistributedZkTest, PathHierarchyTokenizerFactoryTest, CopyFieldTest, TestSimpleQParserPlugin, TestSuggestSpellingConverter, HdfsUnloadDistributedZkTest, AutoCommitTest, TestAtomicUpdateErrorCases, LeaderElectionIntegrationTest, MinimalSchemaTest, ZkCLITest, DistributedSpellCheckComponentTest, SolrIndexConfigTest, TestWriterPerf, PreAnalyzedFieldTest, SampleTest, DefaultValueUpdateProcessorTest, TermVectorComponentTest, TestStandardQParsers, BadComponentTest, TestUniqueKeyFieldResource, TestDynamicFieldCollectionResource, ClusterStateTest, TestRealTimeGet, HighlighterConfigTest, ExternalFileFieldSortTest, TestRecoveryHdfs, SuggestComponentTest, NoCacheHeaderTest, CacheHeaderTest, StatsComponentTest, TestSchemaNameResource, TestFieldTypeResource, TestReload, TestHighlightDedupGrouping, TestUtils, UnloadDistributedZkTest, DeleteReplicaTest, HdfsChaosMonkeySafeLeaderTest, TestSolrXMLSerializer, BasicFunctionalityTest, TestPartialUpdateDeduplication, TermVectorComponentDistributedTest, TestJmxIntegration, PeerSyncTest, TestLuceneMatchVersion, ShardSplitTest]
[junit4] Completed in 57.78s, 1 test, 1 failure <<< FAILURES!
[...truncated 845 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:459: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:439: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:499: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1278: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:911: There were test failures: 362 suites, 1563 tests, 1 failure, 41 ignored (7 assumptions)
Total time: 94 minutes 34 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure